lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject [JENKINS] Lucene-Solr-NightlyTests-trunk - Build # 775 - Still Failing
Date Tue, 25 Aug 2015 11:51:39 GMT
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-trunk/775/

3 tests failed.
REGRESSION:  org.apache.solr.handler.TestSQLHandler.doTest

Error Message:
--> https://127.0.0.1:43667/collection1:java.util.concurrent.ExecutionException: java.io.IOException: --> https://127.0.0.1:47550/collection1/:java.util.concurrent.ExecutionException: java.io.IOException: --> https://127.0.0.1:43804/collection1/:Error opening new searcher

Stack Trace:
java.io.IOException: --> https://127.0.0.1:43667/collection1:java.util.concurrent.ExecutionException: java.io.IOException: --> https://127.0.0.1:47550/collection1/:java.util.concurrent.ExecutionException: java.io.IOException: --> https://127.0.0.1:43804/collection1/:Error opening new searcher
	at __randomizedtesting.SeedInfo.seed([DB5E3E1A35CD34DC:7C1A86BE58762765]:0)
	at org.apache.solr.client.solrj.io.stream.SolrStream.read(SolrStream.java:178)
	at org.apache.solr.handler.TestSQLHandler.getTuples(TestSQLHandler.java:911)
	at org.apache.solr.handler.TestSQLHandler.testParallelBasicGrouping(TestSQLHandler.java:546)
	at org.apache.solr.handler.TestSQLHandler.doTest(TestSQLHandler.java:93)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:497)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1627)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:836)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:872)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:886)
	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:963)
	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:938)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:845)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:747)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:781)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:792)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at java.lang.Thread.run(Thread.java:745)


FAILED:  org.apache.solr.cloud.CollectionsAPIDistributedZkTest.test

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

Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=6440, name=collection4, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest]
Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:58253/_io/rl: Could not find collection : awholynewstresscollection_collection4_1
	at __randomizedtesting.SeedInfo.seed([DB5E3E1A35CD34DC]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:560)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:234)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:226)
	at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:372)
	at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:325)
	at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1086)
	at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:857)
	at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:800)
	at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:895)


FAILED:  org.apache.solr.cloud.hdfs.HdfsCollectionsAPIDistributedZkTest.test

Error Message:
Captured an uncaught exception in thread: Thread[id=12827, name=collection3, state=RUNNABLE, group=TGRP-HdfsCollectionsAPIDistributedZkTest]

Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=12827, name=collection3, state=RUNNABLE, group=TGRP-HdfsCollectionsAPIDistributedZkTest]
Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:33767/ok/gx: Could not find collection : awholynewstresscollection_collection3_1
	at __randomizedtesting.SeedInfo.seed([DB5E3E1A35CD34DC]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:560)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:234)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:226)
	at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:372)
	at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:325)
	at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1086)
	at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:857)
	at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:800)
	at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:895)




Build Log:
[...truncated 10023 lines...]
   [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
   [junit4]   2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/init-core-data-001
   [junit4]   2> 457398 INFO  (SUITE-CollectionsAPIDistributedZkTest-seed#[DB5E3E1A35CD34DC]-worker) [    ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false)
   [junit4]   2> 457398 INFO  (SUITE-CollectionsAPIDistributedZkTest-seed#[DB5E3E1A35CD34DC]-worker) [    ] o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /_io/rl
   [junit4]   2> 457409 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
   [junit4]   2> 457410 INFO  (Thread-3713) [    ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 457410 INFO  (Thread-3713) [    ] o.a.s.c.ZkTestServer Starting server
   [junit4]   2> 457510 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.ZkTestServer start zk server on port:49302
   [junit4]   2> 457510 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 457512 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 457513 INFO  (zkCallback-458-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@3aeb827f name:ZooKeeperConnection Watcher:127.0.0.1:49302 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 457513 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 457514 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 457514 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /solr
   [junit4]   2> 457516 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 457525 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 457536 INFO  (zkCallback-459-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@28d86f3e name:ZooKeeperConnection Watcher:127.0.0.1:49302/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 457536 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 457537 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 457537 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1
   [junit4]   2> 457539 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /collections/collection1/shards
   [junit4]   2> 457541 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection
   [junit4]   2> 457543 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/shards
   [junit4]   2> 457546 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 457546 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 457550 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 457550 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/schema.xml
   [junit4]   2> 457552 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 457552 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 457554 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 457554 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 457555 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 457556 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/protwords.txt
   [junit4]   2> 457557 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 457557 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/currency.xml
   [junit4]   2> 457558 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 457559 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 457560 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 457560 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 457562 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 457562 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 457564 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 457564 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 457566 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 457566 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 457576 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 457591 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 457592 INFO  (zkCallback-460-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@17dd5ceb name:ZooKeeperConnection Watcher:127.0.0.1:49302 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 457592 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 457592 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 457592 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /solr
   [junit4]   2> 457594 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 457596 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 457606 INFO  (zkCallback-461-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@13d7961e name:ZooKeeperConnection Watcher:127.0.0.1:49302/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 457606 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 457606 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 457607 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf2/solrconfig.xml
   [junit4]   2> 457607 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf2/solrconfig.xml
   [junit4]   2> 457609 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf2/schema.xml
   [junit4]   2> 457610 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf2/schema.xml
   [junit4]   2> 457611 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf2/enumsConfig.xml
   [junit4]   2> 457612 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf2/enumsConfig.xml
   [junit4]   2> 457613 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf2/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 457613 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf2/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 457615 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf2/stopwords.txt
   [junit4]   2> 457615 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf2/stopwords.txt
   [junit4]   2> 457621 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf2/protwords.txt
   [junit4]   2> 457621 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf2/protwords.txt
   [junit4]   2> 457622 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf2/currency.xml
   [junit4]   2> 457622 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf2/currency.xml
   [junit4]   2> 457624 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf2/open-exchange-rates.json
   [junit4]   2> 457624 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf2/open-exchange-rates.json
   [junit4]   2> 457625 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf2/mapping-ISOLatin1Accent.txt
   [junit4]   2> 457625 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf2/mapping-ISOLatin1Accent.txt
   [junit4]   2> 457627 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf2/old_synonyms.txt
   [junit4]   2> 457627 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf2/old_synonyms.txt
   [junit4]   2> 457628 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf2/synonyms.txt
   [junit4]   2> 457628 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf2/synonyms.txt
   [junit4]   2> 457629 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.AbstractZkTestCase put /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/elevate.xml to /configs/conf2/elevate.xml
   [junit4]   2> 457630 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient makePath: /configs/conf2/elevate.xml
   [junit4]   2> 457633 WARN  (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [    ] o.a.z.s.NIOServerCnxn caught end of stream exception
   [junit4]   2> EndOfStreamException: Unable to read additional data from client sessionid 0x14f647bd56c0003, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 458026 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/control-001/cores/collection1
   [junit4]   2> 458028 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.e.j.s.Server jetty-9.2.13.v20150730
   [junit4]   2> 458030 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@42bcc847{/_io/rl,null,AVAILABLE}
   [junit4]   2> 458032 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.e.j.s.ServerConnector Started ServerConnector@7d1f407e{HTTP/1.1}{127.0.0.1:38500}
   [junit4]   2> 458032 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.e.j.s.Server Started @461645ms
   [junit4]   2> 458032 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/tempDir-001/control/data, hostContext=/_io/rl, hostPort=38500, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/control-001/cores}
   [junit4]   2> 458033 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@4e0e2f2a
   [junit4]   2> 458033 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/control-001/'
   [junit4]   2> 458048 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 458049 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 458055 INFO  (zkCallback-462-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@348c7ada name:ZooKeeperConnection Watcher:127.0.0.1:49302/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 458055 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 458056 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 458057 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
   [junit4]   2> 458057 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/control-001/solr.xml
   [junit4]   2> 458062 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.CoresLocator Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/control-001/cores
   [junit4]   2> 458063 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.CoreContainer New CoreContainer 1431022615
   [junit4]   2> 458063 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/control-001/]
   [junit4]   2> 458063 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.CoreContainer loading shared library: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/control-001/lib
   [junit4]   2> 458063 WARN  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.SolrResourceLoader Can't find (or read) directory to add to classloader: lib (resolved as: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/control-001/lib).
   [junit4]   2> 458071 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] 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> 458072 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 458072 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 458073 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 458073 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:49302/solr
   [junit4]   2> 458073 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.ZkController zkHost includes chroot
   [junit4]   2> 458073 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 458074 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 458075 INFO  (zkCallback-464-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@166ea42c name:ZooKeeperConnection Watcher:127.0.0.1:49302 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 458076 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 458076 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 458078 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 458079 INFO  (zkCallback-465-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@3ef369f1 name:ZooKeeperConnection Watcher:127.0.0.1:49302/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 458079 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 458080 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue
   [junit4]   2> 458082 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-queue-work
   [junit4]   2> 458083 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-running
   [junit4]   2> 458085 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-completed
   [junit4]   2> 458087 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.c.SolrZkClient makePath: /overseer/collection-map-failure
   [junit4]   2> 458090 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.c.SolrZkClient makePath: /live_nodes
   [junit4]   2> 458091 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.c.SolrZkClient makePath: /aliases.json
   [junit4]   2> 458094 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json
   [junit4]   2> 458095 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.c.SolrZkClient makePath: /security.json
   [junit4]   2> 458096 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38500__io%2Frl
   [junit4]   2> 458097 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1:38500__io%2Frl
   [junit4]   2> 458100 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect
   [junit4]   2> 458102 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/election
   [junit4]   2> 458103 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 458103 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94404600222449670-127.0.0.1:38500__io%2Frl-n_0000000000
   [junit4]   2> 458104 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:38500__io%2Frl
   [junit4]   2> 458104 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.c.SolrZkClient makePath: /overseer_elect/leader
   [junit4]   2> 458107 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.Overseer Overseer (id=94404600222449670-127.0.0.1:38500__io%2Frl-n_0000000000) starting
   [junit4]   2> 458108 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.c.SolrZkClient makePath: /overseer/queue-work
   [junit4]   2> 458120 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.OverseerAutoReplicaFailoverThread Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=10000 autoReplicaFailoverBadNodeExpiration=60000
   [junit4]   2> 458120 INFO  (OverseerCollectionProcessor-94404600222449670-127.0.0.1:38500__io%2Frl-n_0000000000) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.OverseerProcessor Process current queue of overseer operations
   [junit4]   2> 458121 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... 
   [junit4]   2> 458121 INFO  (OverseerStateUpdate-94404600222449670-127.0.0.1:38500__io%2Frl-n_0000000000) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.Overseer Starting to work on the main queue
   [junit4]   2> 458132 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module.
   [junit4]   2> 458132 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.CoreContainer No authentication plugin used.
   [junit4]   2> 458133 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.CoresLocator Looking for core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/control-001/cores
   [junit4]   2> 458134 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.SolrCore Created CoreDescriptor: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, configSetProperties=configsetprops.json, instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/control-001/cores/collection1, collection=control_collection, absoluteInstDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/control-001/cores/collection1/, coreNodeName=, dataDir=data/, shard=}
   [junit4]   2> 458134 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.CoresLocator Found core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/control-001/cores/collection1/
   [junit4]   2> 458134 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.CoresLocator Found 1 core definitions
   [junit4]   2> 458136 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.c.ZkController publishing state=down
   [junit4]   2> 458136 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.s.SolrDispatchFilter user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1
   [junit4]   2> 458136 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init() done
   [junit4]   2> 458136 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.c.ZkController numShards not found on descriptor - reading it from system property
   [junit4]   2> 458138 INFO  (OverseerStateUpdate-94404600222449670-127.0.0.1:38500__io%2Frl-n_0000000000) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "core":"collection1",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"http://127.0.0.1:38500/_io/rl",
   [junit4]   2>   "node_name":"127.0.0.1:38500__io%2Frl",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "shard":null,
   [junit4]   2>   "collection":"control_collection",
   [junit4]   2>   "operation":"state"} current state version: 0
   [junit4]   2> 458138 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.c.ZkController look for our core node name
   [junit4]   2> 458138 INFO  (OverseerStateUpdate-94404600222449670-127.0.0.1:38500__io%2Frl-n_0000000000) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
   [junit4]   2>   "core":"collection1",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"http://127.0.0.1:38500/_io/rl",
   [junit4]   2>   "node_name":"127.0.0.1:38500__io%2Frl",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"down",
   [junit4]   2>   "shard":null,
   [junit4]   2>   "collection":"control_collection",
   [junit4]   2>   "operation":"state"}
   [junit4]   2> 458139 INFO  (OverseerStateUpdate-94404600222449670-127.0.0.1:38500__io%2Frl-n_0000000000) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.o.ClusterStateMutator building a new cName: control_collection
   [junit4]   2> 458139 INFO  (OverseerStateUpdate-94404600222449670-127.0.0.1:38500__io%2Frl-n_0000000000) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.o.ReplicaMutator Assigning new node to shard shard=shard1
   [junit4]   2> 458141 INFO  (zkCallback-465-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl    ] 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> 459140 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.c.ZkController waiting to find shard id in clusterstate for collection1
   [junit4]   2> 459140 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.c.ZkController Check for collection zkNode:control_collection
   [junit4]   2> 459143 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.c.ZkController Collection zkNode exists
   [junit4]   2> 459143 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.c.c.ZkStateReader Load collection config from:/collections/control_collection
   [junit4]   2> 459146 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.c.c.ZkStateReader path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 459146 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/control-001/cores/collection1/'
   [junit4]   2> 459161 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.c.Config loaded config solrconfig.xml with version 0 
   [junit4]   2> 459169 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.c.SolrConfig current version of requestparams : -1
   [junit4]   2> 459173 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 459185 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.c.Config Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 459186 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.s.IndexSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 459192 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 459291 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 459298 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.s.IndexSchema default search field in schema is text
   [junit4]   2> 459299 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.s.IndexSchema unique key field: id
   [junit4]   2> 459309 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
   [junit4]   2> 459312 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
   [junit4]   2> 459314 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 459315 WARN  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
   [junit4]   2> 459315 WARN  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
   [junit4]   2> 459315 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 459316 WARN  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Unknown key IMPORTANT NOTE
   [junit4]   2> 459316 WARN  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Expected key, got STRING
   [junit4]   2> 459318 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl 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-trunk/solr/build/solr-core/test/J1
   [junit4]   2> 459318 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection   x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 459318 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 459319 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl 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-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/control-001/cores/collection1/], dataDir=[null]
   [junit4]   2> 459319 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl 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@2839dd32
   [junit4]   2> 459320 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl 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-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/control-001/cores/collection1/data
   [junit4]   2> 459320 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl 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-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/control-001/cores/collection1/data/index/
   [junit4]   2> 459320 WARN  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl 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-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/control-001/cores/collection1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 459321 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl 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-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/control-001/cores/collection1/data/index
   [junit4]   2> 459321 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1135047096, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 459322 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 	commit{dir=MockDirectoryWrapper(RAMDirectory@7c5cfffe lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2b03a101),segFN=segments_1,generation=1}
   [junit4]   2> 459322 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore newest commit generation = 1
   [junit4]   2> 459326 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 459326 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 459326 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 459326 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 459326 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 459327 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl 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> 459327 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl 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> 459327 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl 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> 459327 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl 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> 459329 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 459330 INFO  (OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:38500__io%2Frl 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-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/control-001/cores/collection1/data/
   [junit4]   2> 459330 WARN  (OldIndexDirectoryCleanupThreadForCore-collection1) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.DirectoryFactory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/control-001/cores/collection1/data/ does not point to a valid data directory; skipping clean-up of old index directories.
   [junit4]   2> 459336 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 459337 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 459338 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
   [junit4]   2> 459341 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.RequestHandlers Registered paths: /admin/mbeans,standard,/update/csv,/update/json/docs,/admin/luke,/admin/segments,/get,/admin/system,/replication,/admin/properties,/config,/schema,/admin/plugins,/admin/logging,/update/json,/admin/threads,/admin/ping,/update,/admin/file
   [junit4]   2> 459341 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl 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> 459342 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl 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> 459342 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl 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> 459343 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Hard AutoCommit: disabled
   [junit4]   2> 459343 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore Soft AutoCommit: disabled
   [junit4]   2> 459344 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=245957286, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 459345 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 	commit{dir=MockDirectoryWrapper(RAMDirectory@7c5cfffe lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2b03a101),segFN=segments_1,generation=1}
   [junit4]   2> 459345 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore newest commit generation = 1
   [junit4]   2> 459345 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@628a13aa[collection1] main
   [junit4]   2> 459345 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl 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> 459346 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl 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> 459346 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl 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> 459346 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 459346 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing RestManager with initArgs: {}
   [junit4]   2> 459347 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl 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> 459347 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl 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> 459347 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl 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> 459347 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.r.RestManager Initializing 0 registered ManagedResources
   [junit4]   2> 459347 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 459348 INFO  (searcherExecutor-1020-thread-1-processing-n:127.0.0.1:38500__io%2Frl x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@628a13aa[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 459348 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl 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> 459348 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl 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> 459348 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl 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> 459349 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl 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 1510473605590286336
   [junit4]   2> 459351 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.u.UpdateLog Took 2.0ms to seed version buckets with highest version 1510473605590286336
   [junit4]   2> 459351 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController watch zkdir /configs/conf1
   [junit4]   2> 459351 INFO  (coreLoadExecutor-1019-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.CoreContainer registering core: collection1
   [junit4]   2> 459352 INFO  (coreZkRegister-1013-thread-1-processing-n:127.0.0.1:38500__io%2Frl x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38500__io%2Frl 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:38500/_io/rl collection:control_collection shard:shard1
   [junit4]   2> 459353 INFO  (coreZkRegister-1013-thread-1-processing-n:127.0.0.1:38500__io%2Frl x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38500__io%2Frl 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> 459356 INFO  (coreZkRegister-1013-thread-1-processing-n:127.0.0.1:38500__io%2Frl x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38500__io%2Frl 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/94404600222449670-core_node1-n_0000000000
   [junit4]   2> 459357 INFO  (coreZkRegister-1013-thread-1-processing-n:127.0.0.1:38500__io%2Frl x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Running the leader process for shard shard1
   [junit4]   2> 459359 INFO  (coreZkRegister-1013-thread-1-processing-n:127.0.0.1:38500__io%2Frl x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
   [junit4]   2> 459359 INFO  (coreZkRegister-1013-thread-1-processing-n:127.0.0.1:38500__io%2Frl x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38500__io%2Frl 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> 459359 INFO  (coreZkRegister-1013-thread-1-processing-n:127.0.0.1:38500__io%2Frl x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:38500/_io/rl/collection1/
   [junit4]   2> 459359 INFO  (OverseerStateUpdate-94404600222449670-127.0.0.1:38500__io%2Frl-n_0000000000) [n:127.0.0.1:38500__io%2Frl    ] 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> 459359 INFO  (coreZkRegister-1013-thread-1-processing-n:127.0.0.1:38500__io%2Frl x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
   [junit4]   2> 459359 INFO  (coreZkRegister-1013-thread-1-processing-n:127.0.0.1:38500__io%2Frl x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.SyncStrategy http://127.0.0.1:38500/_io/rl/collection1/ has no replicas
   [junit4]   2> 459359 INFO  (coreZkRegister-1013-thread-1-processing-n:127.0.0.1:38500__io%2Frl x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38500__io%2Frl 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:38500/_io/rl/collection1/ shard1
   [junit4]   2> 459359 INFO  (coreZkRegister-1013-thread-1-processing-n:127.0.0.1:38500__io%2Frl x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.c.SolrZkClient makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 459364 INFO  (OverseerStateUpdate-94404600222449670-127.0.0.1:38500__io%2Frl-n_0000000000) [n:127.0.0.1:38500__io%2Frl    ] 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:38500/_io/rl",
   [junit4]   2>   "core":"collection1",
   [junit4]   2>   "state":"active"} current state version: 1
   [junit4]   2> 459466 INFO  (zkCallback-465-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl    ] 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> 459515 INFO  (coreZkRegister-1013-thread-1-processing-n:127.0.0.1:38500__io%2Frl x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController We are http://127.0.0.1:38500/_io/rl/collection1/ and leader is http://127.0.0.1:38500/_io/rl/collection1/
   [junit4]   2> 459515 INFO  (coreZkRegister-1013-thread-1-processing-n:127.0.0.1:38500__io%2Frl x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38500__io%2Frl 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:38500/_io/rl
   [junit4]   2> 459515 INFO  (coreZkRegister-1013-thread-1-processing-n:127.0.0.1:38500__io%2Frl x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController I am the leader, no recovery necessary
   [junit4]   2> 459515 INFO  (coreZkRegister-1013-thread-1-processing-n:127.0.0.1:38500__io%2Frl x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38500__io%2Frl c:control_collection s:shard1 r:core_node1 x:collection1] o.a.s.c.ZkController publishing state=active
   [junit4]   2> 459515 INFO  (coreZkRegister-1013-thread-1-processing-n:127.0.0.1:38500__io%2Frl x:collection1 s:shard1 c:control_collection r:core_node1) [n:127.0.0.1:38500__io%2Frl 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> 459517 INFO  (OverseerStateUpdate-94404600222449670-127.0.0.1:38500__io%2Frl-n_0000000000) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.Overseer processMessage: queueSize: 1, message = {
   [junit4]   2>   "core":"collection1",
   [junit4]   2>   "core_node_name":"core_node1",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"http://127.0.0.1:38500/_io/rl",
   [junit4]   2>   "node_name":"127.0.0.1:38500__io%2Frl",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"control_collection",
   [junit4]   2>   "operation":"state"} current state version: 2
   [junit4]   2> 459518 INFO  (OverseerStateUpdate-94404600222449670-127.0.0.1:38500__io%2Frl-n_0000000000) [n:127.0.0.1:38500__io%2Frl    ] o.a.s.c.o.ReplicaMutator Update state numShards=1 message={
   [junit4]   2>   "core":"collection1",
   [junit4]   2>   "core_node_name":"core_node1",
   [junit4]   2>   "roles":null,
   [junit4]   2>   "base_url":"http://127.0.0.1:38500/_io/rl",
   [junit4]   2>   "node_name":"127.0.0.1:38500__io%2Frl",
   [junit4]   2>   "numShards":"1",
   [junit4]   2>   "state":"active",
   [junit4]   2>   "shard":"shard1",
   [junit4]   2>   "collection":"control_collection",
   [junit4]   2>   "operation":"state"}
   [junit4]   2> 459620 INFO  (zkCallback-465-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl    ] 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> 459638 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 459638 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 459640 INFO  (zkCallback-467-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@3701ee5d name:ZooKeeperConnection Watcher:127.0.0.1:49302/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 459640 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 459640 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 459640 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... 
   [junit4]   2> 459643 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.ChaosMonkey monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 459943 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.SolrTestCaseJ4 Writing core.properties file to /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/shard-1-001/cores/collection1
   [junit4]   2> 459944 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.AbstractFullDistribZkTestBase create jetty 1 in directory /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/shard-1-001
   [junit4]   2> 459945 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.e.j.s.Server jetty-9.2.13.v20150730
   [junit4]   2> 459946 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@250ece5e{/_io/rl,null,AVAILABLE}
   [junit4]   2> 459947 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.e.j.s.ServerConnector Started ServerConnector@7dfc4700{HTTP/1.1}{127.0.0.1:33883}
   [junit4]   2> 459947 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.e.j.s.Server Started @463559ms
   [junit4]   2> 459947 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {solr.data.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/tempDir-001/jetty1, solrconfig=solrconfig.xml, hostContext=/_io/rl, hostPort=33883, coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/shard-1-001/cores}
   [junit4]   2> 459947 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.s.SolrDispatchFilter SolrDispatchFilter.init(): sun.misc.Launcher$AppClassLoader@4e0e2f2a
   [junit4]   2> 459947 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/shard-1-001/'
   [junit4]   2> 459962 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 459963 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 459964 INFO  (zkCallback-468-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@3c1fe4d1 name:ZooKeeperConnection Watcher:127.0.0.1:49302/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 459964 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 459965 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 459966 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.s.SolrDispatchFilter Loading solr.xml from SolrHome (not found in ZooKeeper)
   [junit4]   2> 459966 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.SolrXmlConfig Loading container configuration from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/shard-1-001/solr.xml
   [junit4]   2> 459971 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.CoresLocator Config-defined core root directory: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/shard-1-001/cores
   [junit4]   2> 459971 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.CoreContainer New CoreContainer 1937775392
   [junit4]   2> 459971 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/shard-1-001/]
   [junit4]   2> 459971 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.CoreContainer loading shared library: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/shard-1-001/lib
   [junit4]   2> 459971 WARN  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.SolrResourceLoader Can't find (or read) directory to add to classloader: lib (resolved as: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/shard-1-001/lib).
   [junit4]   2> 459979 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] 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> 459980 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 459981 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 459981 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 459981 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:49302/solr
   [junit4]   2> 459981 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.ZkController zkHost includes chroot
   [junit4]   2> 459981 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
   [junit4]   2> 459982 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 459983 INFO  (zkCallback-470-thread-1) [    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@735505e3 name:ZooKeeperConnection Watcher:127.0.0.1:49302 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 459984 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 459984 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [    ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
   [junit4]   2> 459986 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:33883__io%2Frl    ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
   [junit4]   2> 459986 INFO  (zkCallback-471-thread-1-processing-n:127.0.0.1:33883__io%2Frl) [n:127.0.0.1:33883__io%2Frl    ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@4dee4a6e name:ZooKeeperConnection Watcher:127.0.0.1:49302/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 459986 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:33883__io%2Frl    ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
   [junit4]   2> 459990 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:33883__io%2Frl    ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper... 
   [junit4]   2> 460995 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:33883__io%2Frl    ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33883__io%2Frl
   [junit4]   2> 460996 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:33883__io%2Frl    ] o.a.s.c.c.SolrZkClient makePath: /live_nodes/127.0.0.1:33883__io%2Frl
   [junit4]   2> 460998 INFO  (zkCallback-465-thread-1-processing-n:127.0.0.1:38500__io%2Frl) [n:127.0.0.1:38500__io%2Frl    ] 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> 460998 INFO  (zkCallback-471-thread-1-processing-n:127.0.0.1:33883__io%2Frl) [n:127.0.0.1:33883__io%2Frl    ] 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> 460998 INFO  (zkCallback-467-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> 461000 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:33883__io%2Frl    ] o.a.s.c.Overseer Overseer (id=null) closing
   [junit4]   2> 461001 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:33883__io%2Frl    ] o.a.s.c.LeaderElector Joined leadership election with path: /overseer_elect/election/94404600222449674-127.0.0.1:33883__io%2Frl-n_0000000001
   [junit4]   2> 461002 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:33883__io%2Frl    ] o.a.s.c.LeaderElector Watching path /overseer_elect/election/94404600222449670-127.0.0.1:38500__io%2Frl-n_0000000000 to know if I could be the leader
   [junit4]   2> 461011 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:33883__io%2Frl    ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module.
   [junit4]   2> 461011 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:33883__io%2Frl    ] o.a.s.c.CoreContainer No authentication plugin used.
   [junit4]   2> 461012 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:33883__io%2Frl    ] o.a.s.c.CoresLocator Looking for core definitions underneath /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/shard-1-001/cores
   [junit4]   2> 461013 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:33883__io%2Frl    ] o.a.s.c.SolrCore Created CoreDescriptor: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, configSetProperties=configsetprops.json, instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/shard-1-001/cores/collection1, collection=collection1, absoluteInstDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/shard-1-001/cores/collection1/, coreNodeName=, dataDir=data/, shard=}
   [junit4]   2> 461013 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:33883__io%2Frl    ] o.a.s.c.CoresLocator Found core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest_DB5E3E1A35CD34DC-001/shard-1-001/cores/collection1/
   [junit4]   2> 461014 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:33883__io%2Frl    ] o.a.s.c.CoresLocator Found 1 core definitions
   [junit4]   2> 461015 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:33883__io%2Frl    ] o.a.s.s.SolrDispatchFilter user.dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1
   [junit4]   2> 461015 INFO  (TEST-CollectionsAPIDistributedZkTest.test-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:33883__io%2Frl    ] o.a.s.

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

r.ZooKeeper.exists(ZooKeeper.java:1045)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:319)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:316)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:61)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:316)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.ensureExists(ZkCmdExecutor.java:90)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.ensureExists(ZkCmdExecutor.java:84)
   [junit4]   2> 	at org.apache.solr.cloud.DistributedQueue.<init>(DistributedQueue.java:108)
   [junit4]   2> 	... 26 more
   [junit4]   2> 3659076 INFO  (TEST-TestSQLHandler.doTest-seed#[DB5E3E1A35CD34DC]) [    ] o.e.j.s.ServerConnector Stopped ServerConnector@3f2bf445{SSL-http/1.1}{127.0.0.1:0}
   [junit4]   2> 3659076 INFO  (TEST-TestSQLHandler.doTest-seed#[DB5E3E1A35CD34DC]) [    ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@2b722517{/,null,UNAVAILABLE}
   [junit4]   2> 3659079 INFO  (TEST-TestSQLHandler.doTest-seed#[DB5E3E1A35CD34DC]) [n:127.0.0.1:47550_ c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.c.ZkTestServer connecting to 127.0.0.1:55012 55012
   [junit4]   2> 3659388 INFO  (Thread-20772) [    ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:55012 55012
   [junit4]   2> 3659390 WARN  (Thread-20772) [    ] o.a.s.c.ZkTestServer Watch limit violations: 
   [junit4]   2> Maximum concurrent create/delete watches above limit:
   [junit4]   2> 
   [junit4]   2> 	9	/solr/aliases.json
   [junit4]   2> 	6	/solr/security.json
   [junit4]   2> 	5	/solr/configs/conf1
   [junit4]   2> 
   [junit4]   2> Maximum concurrent data watches above limit:
   [junit4]   2> 
   [junit4]   2> 	13	/solr/clusterstate.json
   [junit4]   2> 	4	/solr/collections/collection1/state.json
   [junit4]   2> 
   [junit4]   2> Maximum concurrent children watches above limit:
   [junit4]   2> 
   [junit4]   2> 	13	/solr/live_nodes
   [junit4]   2> 	9	/solr/collections
   [junit4]   2> 	4	/solr/overseer/collection-queue-work
   [junit4]   2> 	3	/solr/overseer/queue
   [junit4]   2> 	2	/solr/overseer/queue-work
   [junit4]   2> 
   [junit4]   2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=TestSQLHandler -Dtests.method=doTest -Dtests.seed=DB5E3E1A35CD34DC -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/x1/jenkins/lucene-data/enwiki.random.lines.txt -Dtests.locale=hu -Dtests.timezone=Africa/Accra -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
   [junit4] ERROR   35.6s J1 | TestSQLHandler.doTest <<<
   [junit4]    > Throwable #1: java.io.IOException: --> https://127.0.0.1:43667/collection1:java.util.concurrent.ExecutionException: java.io.IOException: --> https://127.0.0.1:47550/collection1/:java.util.concurrent.ExecutionException: java.io.IOException: --> https://127.0.0.1:43804/collection1/:Error opening new searcher
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([DB5E3E1A35CD34DC:7C1A86BE58762765]:0)
   [junit4]    > 	at org.apache.solr.client.solrj.io.stream.SolrStream.read(SolrStream.java:178)
   [junit4]    > 	at org.apache.solr.handler.TestSQLHandler.getTuples(TestSQLHandler.java:911)
   [junit4]    > 	at org.apache.solr.handler.TestSQLHandler.testParallelBasicGrouping(TestSQLHandler.java:546)
   [junit4]    > 	at org.apache.solr.handler.TestSQLHandler.doTest(TestSQLHandler.java:93)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:963)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:938)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 3659405 INFO  (SUITE-TestSQLHandler-seed#[DB5E3E1A35CD34DC]-worker) [n:127.0.0.1:47550_ c:collection1 s:shard1 r:core_node4 x:collection1] o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.handler.TestSQLHandler_DB5E3E1A35CD34DC-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene53): {item_i=PostingsFormat(name=LuceneVarGapFixedInterval), n_l1=FSTOrd50, multiDefault=FSTOrd50, intDefault=BlockTreeOrds(blocksize=128), day_i=FSTOrd50, n_dt1=BlockTreeOrds(blocksize=128), n_td1=BlockTreeOrds(blocksize=128), n_d1=FSTOrd50, field_i=FSTOrd50, str_s=PostingsFormat(name=LuceneVarGapFixedInterval), n_f1=BlockTreeOrds(blocksize=128), n_ti1=PostingsFormat(name=LuceneVarGapDocFreqInterval), year_i=PostingsFormat(name=LuceneVarGapDocFreqInterval), rnd_b=PostingsFormat(name=LuceneVarGapDocFreqInterval), n_tl1=BlockTreeOrds(blocksize=128), _version_=BlockTreeOrds(blocksize=128), n_tf1=FSTOrd50, n_tdt1=BlockTreeOrds(blocksize=128), id=PostingsFormat(name=LuceneVarGapDocFreqInterval), text=PostingsFormat(name=LuceneVarGapFixedInterval), timestamp=FSTOrd50, month_i=FSTOrd50}, docValues:{year_i=DocValuesFormat(name=Direct), item_i=DocValuesFormat(name=Lucene50), multiDefault=DocValuesFormat(name=Lucene50), intDefault=DocValuesFormat(name=Memory), day_i=DocValuesFormat(name=Lucene50), id=DocValuesFormat(name=Direct), field_i=DocValuesFormat(name=Lucene50), str_s=DocValuesFormat(name=Lucene50), n_f1=DocValuesFormat(name=Memory), month_i=DocValuesFormat(name=Lucene50)}, sim=DefaultSimilarity, locale=hu, timezone=Africa/Accra
   [junit4]   2> NOTE: Linux 3.13.0-52-generic amd64/Oracle Corporation 1.8.0_45 (64-bit)/cpus=4,threads=1,free=114570512,total=509083648
   [junit4]   2> NOTE: All tests run in this JVM: [DistributedDebugComponentTest, ShardRoutingTest, TestDynamicFieldResource, TestMiniSolrCloudCluster, DeleteLastCustomShardedReplicaTest, TestHdfsUpdateLog, BasicAuthIntegrationTest, TestSha256AuthenticationProvider, HdfsSyncSliceTest, TestAnalyzeInfixSuggestions, ResourceLoaderTest, ZkSolrClientTest, UpdateParamsTest, TestFieldTypeCollectionResource, DistributedTermsComponentTest, TestManagedSchemaFieldTypeResource, TestConfigSets, BasicFunctionalityTest, HdfsNNFailoverTest, ZkControllerTest, TestManagedResourceStorage, CollectionsAPIDistributedZkTest, TestIndexSearcher, TestCharFilters, TestShardHandlerFactory, TestSolrDeletionPolicy2, TestReqParamsAPI, DistributedSuggestComponentTest, CollectionReloadTest, TestSimpleTrackingShardHandler, FieldAnalysisRequestHandlerTest, TestAuthenticationFramework, SliceStateTest, CoreAdminHandlerTest, SpellPossibilityIteratorTest, ShowFileRequestHandlerTest, TestCryptoKeys, TestFuzzyAnalyzedSuggestions, TestLRUStatsCache, TestDefaultSearchFieldResource, LeaderFailoverAfterPartitionTest, CloudExitableDirectoryReaderTest, DisMaxRequestHandlerTest, ReturnFieldsTest, SimpleMLTQParserTest, SuggesterTSTTest, ShardRoutingCustomTest, TestWriterPerf, ExplicitHLLTest, TestAuthorizationFramework, CursorMarkTest, AlternateDirectoryTest, SpellCheckComponentTest, TestCoreDiscovery, TestFastLRUCache, CopyFieldTest, CacheHeaderTest, TestClusterStateMutator, IndexSchemaRuntimeFieldTest, TestStressUserVersions, ScriptEngineTest, TestScoreJoinQPScore, BadComponentTest, NoCacheHeaderTest, TestCoreContainer, TestCloudPivotFacet, ZkStateReaderTest, TestLMDirichletSimilarityFactory, HdfsCollectionsAPIDistributedZkTest, TriLevelCompositeIdRoutingTest, TestTrieFacet, AnalyticsMergeStrategyTest, TestBlobHandler, DistributedFacetPivotSmallAdvancedTest, DistributedMLTComponentTest, SpatialFilterTest, TestMaxScoreQueryParser, TestElisionMultitermQuery, CdcrReplicationDistributedZkTest, DocValuesMissingTest, TestLFUCache, TestValueSourceCache, BJQParserTest, TestRawResponseWriter, AddBlockUpdateTest, TestClassNameShortening, TestComponentsName, TestLMJelinekMercerSimilarityFactory, ConcurrentDeleteAndCreateCollectionTest, DeleteInactiveReplicaTest, DistribJoinFromCollectionTest, HttpPartitionTest, SharedFSAutoReplicaFailoverTest, TestShortCircuitedRequests, HdfsBasicDistributedZk2Test, HdfsRecoverLeaseTest, HdfsRecoveryZkTest, ZkStateWriterTest, CachingDirectoryFactoryTest, ExitableDirectoryReaderTest, QueryResultKeyTest, TestConfigOverlay, TestConfigSetProperties, TestDynamicLoading, TestImplicitCoreProperties, TestInitParams, TestSolrConfigHandler, TestSolrXml, TestReplicationHandlerBackup, TestSQLHandler]
   [junit4] Completed [451/541] on J1 in 35.60s, 1 test, 1 error <<< FAILURES!

[...truncated 292 lines...]
BUILD FAILED
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:782: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:719: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/build.xml:59: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build.xml:233: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/common-build.xml:514: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:1432: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-NightlyTests-trunk/lucene/common-build.xml:987: There were test failures: 541 suites, 2136 tests, 3 errors, 26 ignored (14 assumptions)

Total time: 177 minutes 25 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
Sending email for trigger: Failure



Mime
View raw message