You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2015/05/23 11:18:07 UTC

[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.8.0) - Build # 2335 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/2335/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC

2 tests failed.
FAILED:  org.apache.solr.cloud.CdcrReplicationDistributedZkTest.doTest

Error Message:
expected:<10> but was:<4>

Stack Trace:
java.lang.AssertionError: expected:<10> but was:<4>
	at __randomizedtesting.SeedInfo.seed([FAEF3A0C0661E190:5DAB82A86BDAF229]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.failNotEquals(Assert.java:647)
	at org.junit.Assert.assertEquals(Assert.java:128)
	at org.junit.Assert.assertEquals(Assert.java:472)
	at org.junit.Assert.assertEquals(Assert.java:456)
	at org.apache.solr.cloud.CdcrReplicationDistributedZkTest.doTestReplicationAfterRestart(CdcrReplicationDistributedZkTest.java:219)
	at org.apache.solr.cloud.CdcrReplicationDistributedZkTest.doTest(CdcrReplicationDistributedZkTest.java:44)
	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:960)
	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:935)
	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=4866, name=collection1, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest]

Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=4866, name=collection1, state=RUNNABLE, group=TGRP-CollectionsAPIDistributedZkTest]
Caused by: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at https://127.0.0.1:54582/qdffn/sz: Could not find collection : awholynewstresscollection_collection1_0
	at __randomizedtesting.SeedInfo.seed([FAEF3A0C0661E190]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:560)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:235)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:227)
	at org.apache.solr.client.solrj.impl.LBHttpSolrClient.doRequest(LBHttpSolrClient.java:376)
	at org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:328)
	at org.apache.solr.client.solrj.impl.CloudSolrClient.sendRequest(CloudSolrClient.java:1086)
	at org.apache.solr.client.solrj.impl.CloudSolrClient.requestWithRetryOnStaleState(CloudSolrClient.java:856)
	at org.apache.solr.client.solrj.impl.CloudSolrClient.request(CloudSolrClient.java:799)
	at org.apache.solr.client.solrj.SolrClient.request(SolrClient.java:1220)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest$1CollectionThread.run(CollectionsAPIDistributedZkTest.java:884)




Build Log:
[...truncated 9931 lines...]
   [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
   [junit4]   2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/init-core-data-001
   [junit4]   2> 857155 T4513 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
   [junit4]   2> 857155 T4513 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /qdffn/sz
   [junit4]   2> 857158 T4513 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 857159 T4514 oasc.ZkTestServer$2$1.setClientPort client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 857159 T4514 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 857260 T4513 oasc.ZkTestServer.run start zk server on port:54521
   [junit4]   2> 857260 T4513 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 857261 T4513 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 857270 T4521 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@291323ed name:ZooKeeperConnection Watcher:127.0.0.1:54521 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 857271 T4513 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 857271 T4513 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 857271 T4513 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 857279 T4513 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 857280 T4513 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 857283 T4524 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6e23d3b8 name:ZooKeeperConnection Watcher:127.0.0.1:54521/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 857283 T4513 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 857284 T4513 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 857284 T4513 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 857290 T4513 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 857294 T4513 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 857298 T4513 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 857302 T4513 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 857303 T4513 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 857309 T4513 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 857310 T4513 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 857314 T4513 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 857315 T4513 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 857319 T4513 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 857319 T4513 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 857324 T4513 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 857324 T4513 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 857329 T4513 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 857330 T4513 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 857334 T4513 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 857334 T4513 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 857338 T4513 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 857339 T4513 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 857343 T4513 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 857343 T4513 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 857348 T4513 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 857348 T4513 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 857353 T4513 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 857353 T4513 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 857360 T4513 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 857361 T4513 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 857368 T4527 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6fc0b884 name:ZooKeeperConnection Watcher:127.0.0.1:54521/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 857369 T4513 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 857369 T4513 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 857373 T4513 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 857374 T4513 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 857377 T4530 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6fa38319 name:ZooKeeperConnection Watcher:127.0.0.1:54521 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 857377 T4513 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 857377 T4513 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 857377 T4513 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 857383 T4513 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 857384 T4513 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 857388 T4533 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5dc0e6be name:ZooKeeperConnection Watcher:127.0.0.1:54521/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 857388 T4513 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 857389 T4513 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 857390 T4513 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf2/solrconfig.xml
   [junit4]   2> 857390 T4513 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.xml
   [junit4]   2> 857396 T4513 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf2/schema.xml
   [junit4]   2> 857397 T4513 oascc.SolrZkClient.makePath makePath: /configs/conf2/schema.xml
   [junit4]   2> 857401 T4513 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf2/enumsConfig.xml
   [junit4]   2> 857401 T4513 oascc.SolrZkClient.makePath makePath: /configs/conf2/enumsConfig.xml
   [junit4]   2> 857406 T4513 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf2/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 857406 T4513 oascc.SolrZkClient.makePath makePath: /configs/conf2/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 857410 T4513 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf2/stopwords.txt
   [junit4]   2> 857411 T4513 oascc.SolrZkClient.makePath makePath: /configs/conf2/stopwords.txt
   [junit4]   2> 857416 T4513 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf2/protwords.txt
   [junit4]   2> 857417 T4513 oascc.SolrZkClient.makePath makePath: /configs/conf2/protwords.txt
   [junit4]   2> 857422 T4513 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf2/currency.xml
   [junit4]   2> 857422 T4513 oascc.SolrZkClient.makePath makePath: /configs/conf2/currency.xml
   [junit4]   2> 857427 T4513 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf2/open-exchange-rates.json
   [junit4]   2> 857427 T4513 oascc.SolrZkClient.makePath makePath: /configs/conf2/open-exchange-rates.json
   [junit4]   2> 857432 T4513 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf2/mapping-ISOLatin1Accent.txt
   [junit4]   2> 857433 T4513 oascc.SolrZkClient.makePath makePath: /configs/conf2/mapping-ISOLatin1Accent.txt
   [junit4]   2> 857437 T4513 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf2/old_synonyms.txt
   [junit4]   2> 857437 T4513 oascc.SolrZkClient.makePath makePath: /configs/conf2/old_synonyms.txt
   [junit4]   2> 857444 T4513 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf2/synonyms.txt
   [junit4]   2> 857445 T4513 oascc.SolrZkClient.makePath makePath: /configs/conf2/synonyms.txt
   [junit4]   2> 857449 T4513 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/elevate.xml to /configs/conf2/elevate.xml
   [junit4]   2> 857449 T4513 oascc.SolrZkClient.makePath makePath: /configs/conf2/elevate.xml
   [junit4]   2> 857934 T4513 oas.SolrTestCaseJ4.writeCoreProperties Writing core.properties file to /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/control-001/cores/collection1
   [junit4]   2> 857937 T4513 oejs.Server.doStart jetty-9.2.10.v20150310
   [junit4]   2> 857941 T4513 oejsh.ContextHandler.doStart Started o.e.j.s.ServletContextHandler@4847763a{/qdffn/sz,null,AVAILABLE}
   [junit4]   2> 857950 T4513 oejs.AbstractConnector.doStart Started ServerConnector@48e1ddda{SSL-http/1.1}{127.0.0.1:54529}
   [junit4]   2> 857951 T4513 oejs.Server.doStart Started @861076ms
   [junit4]   2> 857951 T4513 oascse.JettySolrRunner$1.lifeCycleStarted Jetty properties: {hostContext=/qdffn/sz, hostPort=54529, coreRootDirectory=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/control-001/cores}
   [junit4]   2> 857953 T4513 oass.SolrDispatchFilter.init SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@74a14482
   [junit4]   2> 857953 T4513 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/control-001/'
   [junit4]   2> 857985 T4513 oasc.SolrXmlConfig.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/control-001/solr.xml
   [junit4]   2> 857995 T4513 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/control-001/cores
   [junit4]   2> 857996 T4513 oasc.CoreContainer.<init> New CoreContainer 1033192864
   [junit4]   2> 857996 T4513 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/control-001/]
   [junit4]   2> 857996 T4513 oasc.CoreContainer.load loading shared library: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/control-001/lib
   [junit4]   2> 857997 T4513 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: lib (resolved as: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/control-001/lib).
   [junit4]   2> 858007 T4513 oashc.HttpShardHandlerFactory.init 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> 858014 T4513 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 858017 T4513 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 858017 T4513 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 858017 T4513 oasc.CoreContainer.load Node Name: 127.0.0.1
   [junit4]   2> 858017 T4513 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:54521/solr
   [junit4]   2> 858017 T4513 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 858017 T4513 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 858019 T4513 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 858023 T4547 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11bae96f name:ZooKeeperConnection Watcher:127.0.0.1:54521 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 858024 T4513 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 858024 T4513 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 858029 T4513 n:127.0.0.1:54529_qdffn%2Fsz oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 858033 T4550 n:127.0.0.1:54529_qdffn%2Fsz oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@33329c45 name:ZooKeeperConnection Watcher:127.0.0.1:54521/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 858033 T4513 n:127.0.0.1:54529_qdffn%2Fsz oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 858036 T4513 n:127.0.0.1:54529_qdffn%2Fsz oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 858042 T4513 n:127.0.0.1:54529_qdffn%2Fsz oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 858049 T4513 n:127.0.0.1:54529_qdffn%2Fsz oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 858055 T4513 n:127.0.0.1:54529_qdffn%2Fsz oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 858060 T4513 n:127.0.0.1:54529_qdffn%2Fsz oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 858067 T4513 n:127.0.0.1:54529_qdffn%2Fsz oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 858072 T4513 n:127.0.0.1:54529_qdffn%2Fsz oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 858075 T4513 n:127.0.0.1:54529_qdffn%2Fsz oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 858078 T4513 n:127.0.0.1:54529_qdffn%2Fsz oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54529_qdffn%2Fsz
   [junit4]   2> 858080 T4513 n:127.0.0.1:54529_qdffn%2Fsz oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54529_qdffn%2Fsz
   [junit4]   2> 858084 T4513 n:127.0.0.1:54529_qdffn%2Fsz oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 858088 T4513 n:127.0.0.1:54529_qdffn%2Fsz oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 858091 T4513 n:127.0.0.1:54529_qdffn%2Fsz oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 858094 T4513 n:127.0.0.1:54529_qdffn%2Fsz oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:54529_qdffn%2Fsz
   [junit4]   2> 858095 T4513 n:127.0.0.1:54529_qdffn%2Fsz oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 858098 T4513 n:127.0.0.1:54529_qdffn%2Fsz oasc.Overseer.start Overseer (id=93871816636104710-127.0.0.1:54529_qdffn%2Fsz-n_0000000000) starting
   [junit4]   2> 858102 T4513 n:127.0.0.1:54529_qdffn%2Fsz oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 858125 T4513 n:127.0.0.1:54529_qdffn%2Fsz oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=10000 autoReplicaFailoverBadNodeExpiration=60000
   [junit4]   2> 858127 T4552 n:127.0.0.1:54529_qdffn%2Fsz oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 858127 T4513 n:127.0.0.1:54529_qdffn%2Fsz oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 858128 T4551 n:127.0.0.1:54529_qdffn%2Fsz oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 858137 T4513 n:127.0.0.1:54529_qdffn%2Fsz oasc.CoreContainer.initializeAuthenticationPlugin No authentication plugin used.
   [junit4]   2> 858139 T4513 n:127.0.0.1:54529_qdffn%2Fsz oasc.CoreContainer.intializeAuthorizationPlugin Security conf doesn't exist. Skipping setup for authorization module.
   [junit4]   2> 858141 T4513 n:127.0.0.1:54529_qdffn%2Fsz oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/control-001/cores
   [junit4]   2> 858145 T4513 n:127.0.0.1:54529_qdffn%2Fsz oasc.CoreDescriptor.<init> CORE DESCRIPTOR: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, instanceDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/control-001/cores/collection1, collection=control_collection, absoluteInstDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/control-001/cores/collection1/, coreNodeName=, dataDir=data/, shard=}
   [junit4]   2> 858145 T4513 n:127.0.0.1:54529_qdffn%2Fsz oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/control-001/cores/collection1/
   [junit4]   2> 858145 T4513 n:127.0.0.1:54529_qdffn%2Fsz oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 858148 T4554 n:127.0.0.1:54529_qdffn%2Fsz c:control_collection x:collection1 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 858148 T4554 n:127.0.0.1:54529_qdffn%2Fsz c:control_collection x:collection1 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 858150 T4554 n:127.0.0.1:54529_qdffn%2Fsz oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 858150 T4550 n:127.0.0.1:54529_qdffn%2Fsz oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 858153 T4551 n:127.0.0.1:54529_qdffn%2Fsz oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"https://127.0.0.1:54529/qdffn/sz",
   [junit4]   2> 	  "node_name":"127.0.0.1:54529_qdffn%2Fsz",
   [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> 858154 T4551 n:127.0.0.1:54529_qdffn%2Fsz oasco.ReplicaMutator.updateState Update state numShards=1 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"https://127.0.0.1:54529/qdffn/sz",
   [junit4]   2> 	  "node_name":"127.0.0.1:54529_qdffn%2Fsz",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 858155 T4551 n:127.0.0.1:54529_qdffn%2Fsz oasco.ClusterStateMutator.createCollection building a new cName: control_collection
   [junit4]   2> 858155 T4551 n:127.0.0.1:54529_qdffn%2Fsz oasco.ReplicaMutator.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 858157 T4550 n:127.0.0.1:54529_qdffn%2Fsz oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 859152 T4554 n:127.0.0.1:54529_qdffn%2Fsz oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 859152 T4554 n:127.0.0.1:54529_qdffn%2Fsz oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 859154 T4554 n:127.0.0.1:54529_qdffn%2Fsz oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 859154 T4554 n:127.0.0.1:54529_qdffn%2Fsz oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 859155 T4554 n:127.0.0.1:54529_qdffn%2Fsz oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 859156 T4554 n:127.0.0.1:54529_qdffn%2Fsz oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/control-001/cores/collection1/'
   [junit4]   2> 859173 T4554 n:127.0.0.1:54529_qdffn%2Fsz oasc.Config.<init> loaded config solrconfig.xml with version 0 
   [junit4]   2> 859183 T4554 n:127.0.0.1:54529_qdffn%2Fsz oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
   [junit4]   2> 859185 T4554 n:127.0.0.1:54529_qdffn%2Fsz oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 859200 T4554 n:127.0.0.1:54529_qdffn%2Fsz oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 859202 T4554 n:127.0.0.1:54529_qdffn%2Fsz oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 859207 T4554 n:127.0.0.1:54529_qdffn%2Fsz oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 859310 T4554 n:127.0.0.1:54529_qdffn%2Fsz oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 859318 T4554 n:127.0.0.1:54529_qdffn%2Fsz oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 859319 T4554 n:127.0.0.1:54529_qdffn%2Fsz oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 859337 T4554 n:127.0.0.1:54529_qdffn%2Fsz oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 859340 T4554 n:127.0.0.1:54529_qdffn%2Fsz oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 859343 T4554 n:127.0.0.1:54529_qdffn%2Fsz oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 859345 T4554 n:127.0.0.1:54529_qdffn%2Fsz oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 859345 T4554 n:127.0.0.1:54529_qdffn%2Fsz oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 859345 T4554 n:127.0.0.1:54529_qdffn%2Fsz oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 859347 T4554 n:127.0.0.1:54529_qdffn%2Fsz oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 859347 T4554 n:127.0.0.1:54529_qdffn%2Fsz oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 859347 T4554 n:127.0.0.1:54529_qdffn%2Fsz oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 859348 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 859348 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasc.SolrCore.<init> [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/control-001/cores/collection1/], dataDir=[null]
   [junit4]   2> 859348 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5fac9389
   [junit4]   2> 859349 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/control-001/cores/collection1/data
   [junit4]   2> 859349 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/control-001/cores/collection1/data/index/
   [junit4]   2> 859349 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/control-001/cores/collection1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 859349 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/control-001/cores/collection1/data/index
   [junit4]   2> 859350 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=43, maxMergeAtOnceExplicit=44, maxMergedSegmentMB=7.3251953125, floorSegmentMB=1.6396484375, forceMergeDeletesPctAllowed=12.3548586652213, segmentsPerTier=47.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 859351 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@431ef4c1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f6c3c85),segFN=segments_1,generation=1}
   [junit4]   2> 859351 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 859355 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 859356 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 859356 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 859356 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 859356 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 859356 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 859357 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 859357 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 859357 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 859363 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 859364 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 859365 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 859367 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 859370 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasc.RequestHandlers.initHandlersFromConfig 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> 859371 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 859372 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasu.UpdateHandler.<init> Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 859372 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasu.UpdateLog.init Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 859374 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 859374 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 859375 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=26, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=34.158203125, floorSegmentMB=0.9208984375, forceMergeDeletesPctAllowed=13.824061151971407, segmentsPerTier=45.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3192149921694714
   [junit4]   2> 859375 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@431ef4c1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1f6c3c85),segFN=segments_1,generation=1}
   [junit4]   2> 859375 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 859375 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@29543dfb[collection1] main
   [junit4]   2> 859376 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasu.UpdateLog.onFirstSearcher On first searcher opened, looking up max value of version field
   [junit4]   2> 859376 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasu.VersionInfo.getMaxVersionFromIndex Refreshing highest value of _version_ for 65536 version buckets from index
   [junit4]   2> 859376 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasu.VersionInfo.getMaxVersionFromIndex WARN No terms found for _version_, cannot seed version bucket highest value from index
   [junit4]   2> 859376 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasu.UpdateLog.seedBucketsWithHighestVersion WARN Could not find max version in index or recent updates, using new clock 1501949068499222528
   [junit4]   2> 859378 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasu.UpdateLog.seedBucketsWithHighestVersion Took 2 ms to seed version buckets with highest version 1501949068499222528
   [junit4]   2> 859378 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 859380 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 859380 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 859381 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 859381 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 859381 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 859383 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 859383 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 859383 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 859383 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 859384 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasc.ZkController.getConfDirListeners watch zkdir /configs/conf1
   [junit4]   2> 859384 T4555 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@29543dfb[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 859385 T4554 n:127.0.0.1:54529_qdffn%2Fsz x:collection1 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 859387 T4558 n:127.0.0.1:54529_qdffn%2Fsz c:control_collection s:shard1 x:collection1 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:54529/qdffn/sz collection:control_collection shard:shard1
   [junit4]   2> 859387 T4513 n:127.0.0.1:54529_qdffn%2Fsz oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1
   [junit4]   2> 859387 T4513 n:127.0.0.1:54529_qdffn%2Fsz oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 859388 T4558 n:127.0.0.1:54529_qdffn%2Fsz c:control_collection s:shard1 x:collection1 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 859397 T4513 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 859397 T4558 n:127.0.0.1:54529_qdffn%2Fsz c:control_collection s:shard1 x:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 859399 T4513 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 859403 T4550 n:127.0.0.1:54529_qdffn%2Fsz oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 859403 T4561 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@57477399 name:ZooKeeperConnection Watcher:127.0.0.1:54521/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 859404 T4513 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 859404 T4558 n:127.0.0.1:54529_qdffn%2Fsz c:control_collection s:shard1 x:collection1 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 859404 T4558 n:127.0.0.1:54529_qdffn%2Fsz c:control_collection s:shard1 x:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C3160 name=collection1 org.apache.solr.core.SolrCore@4c97774e url=https://127.0.0.1:54529/qdffn/sz/collection1 node=127.0.0.1:54529_qdffn%2Fsz C3160_STATE=coll:control_collection core:collection1 props:{core=collection1, base_url=https://127.0.0.1:54529/qdffn/sz, node_name=127.0.0.1:54529_qdffn%2Fsz, state=down}
   [junit4]   2> 859404 T4558 n:127.0.0.1:54529_qdffn%2Fsz c:control_collection s:shard1 x:collection1 C3160 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:54529/qdffn/sz/collection1/
   [junit4]   2> 859405 T4558 n:127.0.0.1:54529_qdffn%2Fsz c:control_collection s:shard1 x:collection1 C3160 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 859405 T4558 n:127.0.0.1:54529_qdffn%2Fsz c:control_collection s:shard1 x:collection1 C3160 oasc.SyncStrategy.syncToMe https://127.0.0.1:54529/qdffn/sz/collection1/ has no replicas
   [junit4]   2> 859405 T4558 n:127.0.0.1:54529_qdffn%2Fsz c:control_collection s:shard1 x:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:54529/qdffn/sz/collection1/ shard1
   [junit4]   2> 859405 T4558 n:127.0.0.1:54529_qdffn%2Fsz c:control_collection s:shard1 x:collection1 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 859404 T4513 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 859406 T4513 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 859405 T4551 n:127.0.0.1:54529_qdffn%2Fsz oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection"} current state version: 1
   [junit4]   2> 859413 T4513 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 859416 T4550 n:127.0.0.1:54529_qdffn%2Fsz oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 859418 T4551 n:127.0.0.1:54529_qdffn%2Fsz oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:54529/qdffn/sz",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "state":"active"} current state version: 1
   [junit4]   2> 859525 T4550 n:127.0.0.1:54529_qdffn%2Fsz oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 859525 T4561 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 859570 T4558 n:127.0.0.1:54529_qdffn%2Fsz c:control_collection s:shard1 x:collection1 oasc.ZkController.register We are https://127.0.0.1:54529/qdffn/sz/collection1/ and leader is https://127.0.0.1:54529/qdffn/sz/collection1/
   [junit4]   2> 859571 T4558 n:127.0.0.1:54529_qdffn%2Fsz c:control_collection s:shard1 x:collection1 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:54529/qdffn/sz
   [junit4]   2> 859571 T4558 n:127.0.0.1:54529_qdffn%2Fsz c:control_collection s:shard1 x:collection1 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 859571 T4558 n:127.0.0.1:54529_qdffn%2Fsz c:control_collection s:shard1 x:collection1 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 859571 T4558 n:127.0.0.1:54529_qdffn%2Fsz c:control_collection s:shard1 x:collection1 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 859573 T4550 n:127.0.0.1:54529_qdffn%2Fsz oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 859576 T4551 n:127.0.0.1:54529_qdffn%2Fsz oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"https://127.0.0.1:54529/qdffn/sz",
   [junit4]   2> 	  "node_name":"127.0.0.1:54529_qdffn%2Fsz",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "operation":"state"} current state version: 2
   [junit4]   2> 859579 T4551 n:127.0.0.1:54529_qdffn%2Fsz oasco.ReplicaMutator.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"https://127.0.0.1:54529/qdffn/sz",
   [junit4]   2> 	  "node_name":"127.0.0.1:54529_qdffn%2Fsz",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 859687 T4561 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 859687 T4550 n:127.0.0.1:54529_qdffn%2Fsz oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 859822 T4513 oas.SolrTestCaseJ4.writeCoreProperties Writing core.properties file to /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-1-001/cores/collection1
   [junit4]   2> 859825 T4513 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1 in directory /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-1-001
   [junit4]   2> 859827 T4513 oejs.Server.doStart jetty-9.2.10.v20150310
   [junit4]   2> 859840 T4513 oejsh.ContextHandler.doStart Started o.e.j.s.ServletContextHandler@36f1181d{/qdffn/sz,null,AVAILABLE}
   [junit4]   2> 859846 T4513 oejs.AbstractConnector.doStart Started ServerConnector@412068a3{SSL-http/1.1}{127.0.0.1:54533}
   [junit4]   2> 859846 T4513 oejs.Server.doStart Started @862971ms
   [junit4]   2> 859847 T4513 oascse.JettySolrRunner$1.lifeCycleStarted Jetty properties: {solrconfig=solrconfig.xml, hostContext=/qdffn/sz, hostPort=54533, coreRootDirectory=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-1-001/cores}
   [junit4]   2> 859850 T4513 oass.SolrDispatchFilter.init SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@74a14482
   [junit4]   2> 859850 T4513 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-1-001/'
   [junit4]   2> 859881 T4513 oasc.SolrXmlConfig.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-1-001/solr.xml
   [junit4]   2> 859891 T4513 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-1-001/cores
   [junit4]   2> 859891 T4513 oasc.CoreContainer.<init> New CoreContainer 865936366
   [junit4]   2> 859892 T4513 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-1-001/]
   [junit4]   2> 859893 T4513 oasc.CoreContainer.load loading shared library: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-1-001/lib
   [junit4]   2> 859893 T4513 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: lib (resolved as: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-1-001/lib).
   [junit4]   2> 859904 T4513 oashc.HttpShardHandlerFactory.init 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> 859910 T4513 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 859913 T4513 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 859914 T4513 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 859914 T4513 oasc.CoreContainer.load Node Name: 127.0.0.1
   [junit4]   2> 859914 T4513 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:54521/solr
   [junit4]   2> 859914 T4513 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 859914 T4513 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 859916 T4513 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 859919 T4575 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@bf0e4ef name:ZooKeeperConnection Watcher:127.0.0.1:54521 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 859920 T4513 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 859921 T4513 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 859926 T4513 n:127.0.0.1:54533_qdffn%2Fsz oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 859930 T4578 n:127.0.0.1:54533_qdffn%2Fsz oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4fe6e4ad name:ZooKeeperConnection Watcher:127.0.0.1:54521/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 859930 T4513 n:127.0.0.1:54533_qdffn%2Fsz oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 859947 T4513 n:127.0.0.1:54533_qdffn%2Fsz oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 860966 T4513 n:127.0.0.1:54533_qdffn%2Fsz oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54533_qdffn%2Fsz
   [junit4]   2> 860970 T4513 n:127.0.0.1:54533_qdffn%2Fsz oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54533_qdffn%2Fsz
   [junit4]   2> 860981 T4513 n:127.0.0.1:54533_qdffn%2Fsz oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 860985 T4513 n:127.0.0.1:54533_qdffn%2Fsz oasc.CoreContainer.initializeAuthenticationPlugin No authentication plugin used.
   [junit4]   2> 860987 T4513 n:127.0.0.1:54533_qdffn%2Fsz oasc.CoreContainer.intializeAuthorizationPlugin Security conf doesn't exist. Skipping setup for authorization module.
   [junit4]   2> 860992 T4513 n:127.0.0.1:54533_qdffn%2Fsz oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-1-001/cores
   [junit4]   2> 860996 T4513 n:127.0.0.1:54533_qdffn%2Fsz oasc.CoreDescriptor.<init> CORE DESCRIPTOR: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, instanceDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-1-001/cores/collection1, collection=collection1, absoluteInstDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-1-001/cores/collection1/, coreNodeName=, dataDir=data/, shard=}
   [junit4]   2> 860996 T4513 n:127.0.0.1:54533_qdffn%2Fsz oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-1-001/cores/collection1/
   [junit4]   2> 860997 T4513 n:127.0.0.1:54533_qdffn%2Fsz oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 861002 T4579 n:127.0.0.1:54533_qdffn%2Fsz c:collection1 x:collection1 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 861002 T4579 n:127.0.0.1:54533_qdffn%2Fsz c:collection1 x:collection1 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 861004 T4550 n:127.0.0.1:54529_qdffn%2Fsz oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 861005 T4579 n:127.0.0.1:54533_qdffn%2Fsz oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 861008 T4551 n:127.0.0.1:54529_qdffn%2Fsz oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"https://127.0.0.1:54533/qdffn/sz",
   [junit4]   2> 	  "node_name":"127.0.0.1:54533_qdffn%2Fsz",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"} current state version: 3
   [junit4]   2> 861011 T4551 n:127.0.0.1:54529_qdffn%2Fsz oasco.ReplicaMutator.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"https://127.0.0.1:54533/qdffn/sz",
   [junit4]   2> 	  "node_name":"127.0.0.1:54533_qdffn%2Fsz",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 861011 T4551 n:127.0.0.1:54529_qdffn%2Fsz oasco.ClusterStateMutator.createCollection building a new cName: collection1
   [junit4]   2> 861011 T4551 n:127.0.0.1:54529_qdffn%2Fsz oasco.ReplicaMutator.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 861120 T4578 n:127.0.0.1:54533_qdffn%2Fsz oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 861120 T4550 n:127.0.0.1:54529_qdffn%2Fsz oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 861122 T4561 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 862008 T4579 n:127.0.0.1:54533_qdffn%2Fsz oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 862008 T4579 n:127.0.0.1:54533_qdffn%2Fsz oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 862050 T4579 n:127.0.0.1:54533_qdffn%2Fsz oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 862057 T4579 n:127.0.0.1:54533_qdffn%2Fsz oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 862072 T4579 n:127.0.0.1:54533_qdffn%2Fsz oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 862072 T4579 n:127.0.0.1:54533_qdffn%2Fsz oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-1-001/cores/collection1/'
   [junit4]   2> 862100 T4579 n:127.0.0.1:54533_qdffn%2Fsz oasc.Config.<init> loaded config solrconfig.xml with version 0 
   [junit4]   2> 862115 T4579 n:127.0.0.1:54533_qdffn%2Fsz oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
   [junit4]   2> 862170 T4579 n:127.0.0.1:54533_qdffn%2Fsz oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 862192 T4579 n:127.0.0.1:54533_qdffn%2Fsz oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 862199 T4579 n:127.0.0.1:54533_qdffn%2Fsz oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 862206 T4579 n:127.0.0.1:54533_qdffn%2Fsz oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 862394 T4579 n:127.0.0.1:54533_qdffn%2Fsz oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 862413 T4579 n:127.0.0.1:54533_qdffn%2Fsz oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 862414 T4579 n:127.0.0.1:54533_qdffn%2Fsz oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 862442 T4579 n:127.0.0.1:54533_qdffn%2Fsz oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 862462 T4579 n:127.0.0.1:54533_qdffn%2Fsz oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 862467 T4579 n:127.0.0.1:54533_qdffn%2Fsz oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 862471 T4579 n:127.0.0.1:54533_qdffn%2Fsz oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 862471 T4579 n:127.0.0.1:54533_qdffn%2Fsz oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 862472 T4579 n:127.0.0.1:54533_qdffn%2Fsz oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 862475 T4579 n:127.0.0.1:54533_qdffn%2Fsz oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 862475 T4579 n:127.0.0.1:54533_qdffn%2Fsz oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 862476 T4579 n:127.0.0.1:54533_qdffn%2Fsz oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 862476 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 862476 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasc.SolrCore.<init> [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-1-001/cores/collection1/], dataDir=[null]
   [junit4]   2> 862476 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5fac9389
   [junit4]   2> 862477 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-1-001/cores/collection1/data
   [junit4]   2> 862477 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-1-001/cores/collection1/data/index/
   [junit4]   2> 862477 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-1-001/cores/collection1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 862478 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-1-001/cores/collection1/data/index
   [junit4]   2> 862481 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=43, maxMergeAtOnceExplicit=44, maxMergedSegmentMB=7.3251953125, floorSegmentMB=1.6396484375, forceMergeDeletesPctAllowed=12.3548586652213, segmentsPerTier=47.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 862482 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@28c3c685 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@39509858),segFN=segments_1,generation=1}
   [junit4]   2> 862482 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 862492 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 862492 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 862493 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 862493 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 862493 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 862493 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 862493 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 862494 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 862494 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 862504 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 862508 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 862511 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 862512 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 862526 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasc.RequestHandlers.initHandlersFromConfig 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> 862527 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 862529 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasu.UpdateHandler.<init> Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 862530 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasu.UpdateLog.init Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 862535 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 862535 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 862537 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=26, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=34.158203125, floorSegmentMB=0.9208984375, forceMergeDeletesPctAllowed=13.824061151971407, segmentsPerTier=45.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3192149921694714
   [junit4]   2> 862537 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@28c3c685 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@39509858),segFN=segments_1,generation=1}
   [junit4]   2> 862537 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 862538 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@4ae09834[collection1] main
   [junit4]   2> 862538 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasu.UpdateLog.onFirstSearcher On first searcher opened, looking up max value of version field
   [junit4]   2> 862538 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasu.VersionInfo.getMaxVersionFromIndex Refreshing highest value of _version_ for 65536 version buckets from index
   [junit4]   2> 862539 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasu.VersionInfo.getMaxVersionFromIndex WARN No terms found for _version_, cannot seed version bucket highest value from index
   [junit4]   2> 862539 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasu.UpdateLog.seedBucketsWithHighestVersion WARN Could not find max version in index or recent updates, using new clock 1501949071815868416
   [junit4]   2> 862541 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasu.UpdateLog.seedBucketsWithHighestVersion Took 3 ms to seed version buckets with highest version 1501949071815868416
   [junit4]   2> 862541 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 862549 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 862549 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 862552 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 862552 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 862552 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 862553 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 862553 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 862553 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 862553 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 862555 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasc.ZkController.getConfDirListeners watch zkdir /configs/conf1
   [junit4]   2> 862557 T4580 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4ae09834[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 862558 T4579 n:127.0.0.1:54533_qdffn%2Fsz x:collection1 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 862566 T4583 n:127.0.0.1:54533_qdffn%2Fsz c:collection1 s:shard2 x:collection1 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:54533/qdffn/sz collection:collection1 shard:shard2
   [junit4]   2> 862566 T4513 n:127.0.0.1:54533_qdffn%2Fsz oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1
   [junit4]   2> 862567 T4513 n:127.0.0.1:54533_qdffn%2Fsz oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 862573 T4583 n:127.0.0.1:54533_qdffn%2Fsz c:collection1 s:shard2 x:collection1 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 862612 T4583 n:127.0.0.1:54533_qdffn%2Fsz c:collection1 s:shard2 x:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 862622 T4550 n:127.0.0.1:54529_qdffn%2Fsz oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 862626 T4551 n:127.0.0.1:54529_qdffn%2Fsz oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1"} current state version: 4
   [junit4]   2> 862627 T4583 n:127.0.0.1:54533_qdffn%2Fsz c:collection1 s:shard2 x:collection1 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 862627 T4583 n:127.0.0.1:54533_qdffn%2Fsz c:collection1 s:shard2 x:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C3161 name=collection1 org.apache.solr.core.SolrCore@1beff0bf url=https://127.0.0.1:54533/qdffn/sz/collection1 node=127.0.0.1:54533_qdffn%2Fsz C3161_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=https://127.0.0.1:54533/qdffn/sz, node_name=127.0.0.1:54533_qdffn%2Fsz, state=down}
   [junit4]   2> 862627 T4583 n:127.0.0.1:54533_qdffn%2Fsz c:collection1 s:shard2 x:collection1 C3161 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:54533/qdffn/sz/collection1/
   [junit4]   2> 862627 T4583 n:127.0.0.1:54533_qdffn%2Fsz c:collection1 s:shard2 x:collection1 C3161 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 862627 T4583 n:127.0.0.1:54533_qdffn%2Fsz c:collection1 s:shard2 x:collection1 C3161 oasc.SyncStrategy.syncToMe https://127.0.0.1:54533/qdffn/sz/collection1/ has no replicas
   [junit4]   2> 862627 T4583 n:127.0.0.1:54533_qdffn%2Fsz c:collection1 s:shard2 x:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:54533/qdffn/sz/collection1/ shard2
   [junit4]   2> 862628 T4583 n:127.0.0.1:54533_qdffn%2Fsz c:collection1 s:shard2 x:collection1 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 862629 T4550 n:127.0.0.1:54529_qdffn%2Fsz oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 862629 T4561 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 862633 T4578 n:127.0.0.1:54533_qdffn%2Fsz oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 862661 T4550 n:127.0.0.1:54529_qdffn%2Fsz oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 862663 T4551 n:127.0.0.1:54529_qdffn%2Fsz oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:54533/qdffn/sz",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "state":"active"} current state version: 5
   [junit4]   2> 862793 T4561 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 862793 T4550 n:127.0.0.1:54529_qdffn%2Fsz oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 862794 T4578 n:127.0.0.1:54533_qdffn%2Fsz oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 862821 T4583 n:127.0.0.1:54533_qdffn%2Fsz c:collection1 s:shard2 x:collection1 oasc.ZkController.register We are https://127.0.0.1:54533/qdffn/sz/collection1/ and leader is https://127.0.0.1:54533/qdffn/sz/collection1/
   [junit4]   2> 862822 T4583 n:127.0.0.1:54533_qdffn%2Fsz c:collection1 s:shard2 x:collection1 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:54533/qdffn/sz
   [junit4]   2> 862822 T4583 n:127.0.0.1:54533_qdffn%2Fsz c:collection1 s:shard2 x:collection1 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 862822 T4583 n:127.0.0.1:54533_qdffn%2Fsz c:collection1 s:shard2 x:collection1 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 862822 T4583 n:127.0.0.1:54533_qdffn%2Fsz c:collection1 s:shard2 x:collection1 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 862826 T4550 n:127.0.0.1:54529_qdffn%2Fsz oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 862830 T4551 n:127.0.0.1:54529_qdffn%2Fsz oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"https://127.0.0.1:54533/qdffn/sz",
   [junit4]   2> 	  "node_name":"127.0.0.1:54533_qdffn%2Fsz",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"} current state version: 6
   [junit4]   2> 862834 T4551 n:127.0.0.1:54529_qdffn%2Fsz oasco.ReplicaMutator.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"https://127.0.0.1:54533/qdffn/sz",
   [junit4]   2> 	  "node_name":"127.0.0.1:54533_qdffn%2Fsz",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 862952 T4561 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 862952 T4578 n:127.0.0.1:54533_qdffn%2Fsz oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 862953 T4550 n:127.0.0.1:54529_qdffn%2Fsz oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 863273 T4513 oas.SolrTestCaseJ4.writeCoreProperties Writing core.properties file to /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-2-001/cores/collection1
   [junit4]   2> 863277 T4513 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2 in directory /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-2-001
   [junit4]   2> 863280 T4513 oejs.Server.doStart jetty-9.2.10.v20150310
   [junit4]   2> 863292 T4513 oejsh.ContextHandler.doStart Started o.e.j.s.ServletContextHandler@4b8db027{/qdffn/sz,null,AVAILABLE}
   [junit4]   2> 863315 T4513 oejs.AbstractConnector.doStart Started ServerConnector@3f713bc3{SSL-http/1.1}{127.0.0.1:54582}
   [junit4]   2> 863315 T4513 oejs.Server.doStart Started @866438ms
   [junit4]   2> 863316 T4513 oascse.JettySolrRunner$1.lifeCycleStarted Jetty properties: {solrconfig=solrconfig.xml, hostContext=/qdffn/sz, hostPort=54582, coreRootDirectory=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-2-001/cores}
   [junit4]   2> 863324 T4513 oass.SolrDispatchFilter.init SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@74a14482
   [junit4]   2> 863324 T4513 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-2-001/'
   [junit4]   2> 863378 T4513 oasc.SolrXmlConfig.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-2-001/solr.xml
   [junit4]   2> 863408 T4513 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-2-001/cores
   [junit4]   2> 863409 T4513 oasc.CoreContainer.<init> New CoreContainer 1662929107
   [junit4]   2> 863409 T4513 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-2-001/]
   [junit4]   2> 863409 T4513 oasc.CoreContainer.load loading shared library: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CollectionsAPIDistributedZkTest FAEF3A0C0661E190-001/shard-2-

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

connecting to 127.0.0.1:57737 57737
   [junit4]   2> 2399838 T8848 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:57737 57737
   [junit4]   2> 2400905 T8848 oasc.ZkTestServer$ZKServerMain.runFromConfig WARN Watch limit violations: 
   [junit4]   2> 	Maximum concurrent create/delete watches above limit:
   [junit4]   2> 	
   [junit4]   2> 		98	/solr/aliases.json
   [junit4]   2> 		98	/solr/clusterstate.json
   [junit4]   2> 		50	/solr/configs/conf1
   [junit4]   2> 		21	/solr/collections/source_collection/state.json
   [junit4]   2> 		21	/solr/collections/target_collection/state.json
   [junit4]   2> 		2	/solr/collections/source_collection/leaders/shard1
   [junit4]   2> 		2	/solr/collections/source_collection/leaders/shard2
   [junit4]   2> 		2	/solr/collections/tmp_collection/leaders/shard1
   [junit4]   2> 		2	/solr/collections/tmp_collection/leaders/shard2
   [junit4]   2> 		2	/solr/collections/target_collection/leaders/shard1
   [junit4]   2> 		2	/solr/collections/target_collection/leaders/shard2
   [junit4]   2> 	
   [junit4]   2> 	Maximum concurrent data watches above limit:
   [junit4]   2> 	
   [junit4]   2> 		26	/solr/collections/source_collection/cdcr/state/process
   [junit4]   2> 		21	/solr/collections/target_collection/cdcr/state/buffer
   [junit4]   2> 		21	/solr/collections/source_collection/cdcr/state/buffer
   [junit4]   2> 		21	/solr/collections/target_collection/cdcr/state/process
   [junit4]   2> 		8	/solr/collections/tmp_collection/cdcr/state/process
   [junit4]   2> 		8	/solr/collections/tmp_collection/cdcr/state/buffer
   [junit4]   2> 		2	/solr/collections/target_collection/leader_elect/shard1/election/93871904334348306-core_node4-n_0000000000
   [junit4]   2> 		2	/solr/overseer_elect/election/93871904334348312-127.0.0.1:57867_-n_0000000007
   [junit4]   2> 		2	/solr/overseer_elect/election/93871904334348294-127.0.0.1:57750_-n_0000000001
   [junit4]   2> 		2	/solr/collections/target_collection/leader_elect/shard2/election/93871904334348310-core_node3-n_0000000000
   [junit4]   2> 		2	/solr/overseer_elect/election/93871904334348306-127.0.0.1:57825_-n_0000000004
   [junit4]   2> 	
   [junit4]   2> 	Maximum concurrent children watches above limit:
   [junit4]   2> 	
   [junit4]   2> 		96	/solr/live_nodes
   [junit4]   2> 		6	/solr/overseer/collection-queue-work
   [junit4]   2> 		3	/solr/overseer/queue
   [junit4]   2> 	
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=CdcrReplicationDistributedZkTest -Dtests.method=doTest -Dtests.seed=FAEF3A0C0661E190 -Dtests.slow=true -Dtests.locale=en_SG -Dtests.timezone=Etc/GMT0 -Dtests.asserts=true -Dtests.file.encoding=UTF-8
   [junit4] FAILURE  206s J0 | CdcrReplicationDistributedZkTest.doTest <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: expected:<10> but was:<4>
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([FAEF3A0C0661E190:5DAB82A86BDAF229]:0)
   [junit4]    > 	at org.apache.solr.cloud.CdcrReplicationDistributedZkTest.doTestReplicationAfterRestart(CdcrReplicationDistributedZkTest.java:219)
   [junit4]    > 	at org.apache.solr.cloud.CdcrReplicationDistributedZkTest.doTest(CdcrReplicationDistributedZkTest.java:44)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:960)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:935)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 2400916 T8847 c:source_collection s:shard1 x:source_collection_shard1_replica1 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.CdcrReplicationDistributedZkTest FAEF3A0C0661E190-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene50), sim=DefaultSimilarity, locale=en_SG, timezone=Etc/GMT0
   [junit4]   2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.8.0_45 (64-bit)/cpus=3,threads=1,free=226926280,total=518979584
   [junit4]   2> NOTE: All tests run in this JVM: [ResponseLogComponentTest, TestUpdate, RequiredFieldsTest, EnumFieldTest, TestExactSharedStatsCache, SuggesterWFSTTest, TestSurroundQueryParser, TestExceedMaxTermLength, DefaultValueUpdateProcessorTest, TestStressRecovery, TestNRTOpen, TestCloudSchemaless, TestUniqueKeyFieldResource, TestBM25SimilarityFactory, TestDefaultStatsCache, QueryElevationComponentTest, TestCharFilters, OutputWriterTest, TestGroupingSearch, TestFreeTextSuggestions, CircularListTest, TestJmxIntegration, HardAutoCommitTest, HdfsNNFailoverTest, MultiTermTest, TestManagedSchemaDynamicFieldResource, SampleTest, PrimUtilsTest, TestInitQParser, TimeZoneUtilsTest, TestDistributedStatsComponentCardinality, TestFieldTypeCollectionResource, TestChildDocTransformer, TestNoOpRegenerator, TestIndexSearcher, SimpleMLTQParserTest, TestCollationField, CoreMergeIndexesAdminHandlerTest, TestManagedSchemaFieldResource, TestExpandComponent, AnalysisAfterCoreReloadTest, CoreAdminHandlerTest, ClusterStateUpdateTest, TestJsonFacets, TestWriterPerf, TestImplicitCoreProperties, TestRestManager, TestHighFrequencyDictionaryFactory, TestFileDictionaryLookup, DistributedFacetPivotWhiteBoxTest, TestQueryUtils, StressHdfsTest, TestRawResponseWriter, ClusterStateTest, TestRemoveLastDynamicCopyField, TestBinaryField, TestLazyCores, TestCursorMarkWithoutUniqueKey, TestCollationFieldDocValues, TestAuthorizationFramework, TestCSVResponseWriter, HdfsSyncSliceTest, CollectionsAPIAsyncDistributedZkTest, DeleteInactiveReplicaTest, AlternateDirectoryTest, TestPerFieldSimilarity, TestReRankQParserPlugin, URLClassifyProcessorTest, CacheHeaderTest, ConnectionManagerTest, MultiThreadedOCPTest, SolrInfoMBeanTest, CoreAdminRequestStatusTest, SharedFSAutoReplicaFailoverTest, TestSortingResponseWriter, SortByFunctionTest, NumericFieldsTest, TestDocumentBuilder, TestTrackingShardHandlerFactory, CursorMarkTest, IgnoreCommitOptimizeUpdateProcessorFactoryTest, TestPostingsSolrHighlighter, TestLRUCache, DOMUtilTest, TestCloudPivotFacet, SolrIndexSplitterTest, DistanceFunctionTest, AtomicUpdatesTest, TestSchemaVersionResource, TestSolrQueryParserDefaultOperatorResource, TestExtendedDismaxParser, BasicDistributedZkTest, TestFastLRUCache, ShardRoutingTest, ShowFileRequestHandlerTest, TestAnalyzedSuggestions, TestConfigOverlay, TestManagedSynonymFilterFactory, BaseCdcrDistributedZkTest, TestReplicationHandler, TestShardHandlerFactory, InfoHandlerTest, CollectionReloadTest, TestLFUCache, TestCoreContainer, PreAnalyzedFieldTest, TestCloudManagedSchema, TestQueryTypes, NoCacheHeaderTest, OutOfBoxZkACLAndCredentialsProvidersTest, TestSchemaNameResource, TestIndexingPerformance, TestElisionMultitermQuery, RulesTest, TestFieldCollectionResource, DistanceUnitsTest, TestBinaryResponseWriter, QueryResultKeyTest, TestPivotHelperCode, TestExactStatsCache, SimpleCollectionCreateDeleteTest, SliceStateTest, ChaosMonkeySafeLeaderTest, UnloadDistributedZkTest, SyncSliceTest, OverseerTest, LeaderElectionIntegrationTest, RecoveryZkTest, TestRandomFaceting, LeaderElectionTest, ZkSolrClientTest, TestZkChroot, TestRandomDVFaceting, ZkCLITest, ShardRoutingCustomTest, TestDistributedSearch, TestSolr4Spatial, SolrCmdDistributorTest, PeerSyncTest, BadIndexSchemaTest, ConvertedLegacyTest, TestSort, TestFunctionQuery, DirectUpdateHandlerTest, HighlighterTest, SoftAutoCommitTest, SuggesterFSTTest, TestFoldingMultitermQuery, SuggesterTest, SpatialFilterTest, PolyFieldTest, FieldMutatingUpdateProcessorTest, TestAtomicUpdateErrorCases, TestWordDelimiterFilterFactory, DirectUpdateHandlerOptimizeTest, DocValuesMultiTest, TestSolrDeletionPolicy1, DebugComponentTest, LukeRequestHandlerTest, DocumentAnalysisRequestHandlerTest, XmlUpdateRequestHandlerTest, DocumentBuilderTest, PathHierarchyTokenizerFactoryTest, MoreLikeThisHandlerTest, TestArbitraryIndexDir, IndexSchemaRuntimeFieldTest, SolrPluginUtilsTest, JSONWriterTest, UniqFieldsUpdateProcessorFactoryTest, JsonLoaderTest, PingRequestHandlerTest, HighlighterConfigTest, TestQuerySenderListener, UpdateParamsTest, TestQuerySenderNoQuery, BadComponentTest, TestDocSet, TestConfig, DirectSolrConnectionTest, TestPhraseSuggestions, TestSweetSpotSimilarityFactory, TestLMJelinekMercerSimilarityFactory, TestIBSimilarityFactory, ResourceLoaderTest, ScriptEngineTest, ChaosMonkeyNothingIsSafeTest, TestTolerantSearch, TestEmbeddedSolrServerConstructors, AliasIntegrationTest, CdcrReplicationDistributedZkTest]
   [junit4] Completed [390/502] on J0 in 205.59s, 1 test, 1 failure <<< FAILURES!

[...truncated 356 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:526: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:474: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:61: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/extra-targets.xml:39: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build.xml:229: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/common-build.xml:512: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1415: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:973: There were test failures: 502 suites, 1986 tests, 1 error, 1 failure, 62 ignored (24 assumptions)

Total time: 80 minutes 14 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any



[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.8.0) - Build # 2336 - Still Failing!

Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/2336/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseSerialGC

4 tests failed.
FAILED:  org.apache.solr.cloud.CollectionsAPIAsyncDistributedZkTest.testSolrJAPICalls

Error Message:
Shard split did not complete. Last recorded state: running expected:<[completed]> but was:<[running]>

Stack Trace:
org.junit.ComparisonFailure: Shard split did not complete. Last recorded state: running expected:<[completed]> but was:<[running]>
	at __randomizedtesting.SeedInfo.seed([B073F48B42910119:E81778EA44FBA9CD]:0)
	at org.junit.Assert.assertEquals(Assert.java:125)
	at org.apache.solr.cloud.CollectionsAPIAsyncDistributedZkTest.testSolrJAPICalls(CollectionsAPIAsyncDistributedZkTest.java:101)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java: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:960)
	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:935)
	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.search.TestCollapseQParserPlugin.testMissingFieldParam

Error Message:
Test abandoned because suite timeout was reached.

Stack Trace:
java.lang.Exception: Test abandoned because suite timeout was reached.
	at __randomizedtesting.SeedInfo.seed([B073F48B42910119]:0)


FAILED:  junit.framework.TestSuite.org.apache.solr.search.TestCollapseQParserPlugin

Error Message:
Suite timeout exceeded (>= 7200000 msec).

Stack Trace:
java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
	at __randomizedtesting.SeedInfo.seed([B073F48B42910119]:0)


FAILED:  org.apache.solr.cloud.CdcrReplicationDistributedZkTest.doTest

Error Message:
expected:<st[art]ed> but was:<st[opp]ed>

Stack Trace:
org.junit.ComparisonFailure: expected:<st[art]ed> but was:<st[opp]ed>
	at __randomizedtesting.SeedInfo.seed([B073F48B42910119:17374C2F2F2A12A0]:0)
	at org.junit.Assert.assertEquals(Assert.java:125)
	at org.junit.Assert.assertEquals(Assert.java:147)
	at org.apache.solr.cloud.BaseCdcrDistributedZkTest.assertState(BaseCdcrDistributedZkTest.java:255)
	at org.apache.solr.cloud.CdcrReplicationDistributedZkTest.doTestTargetCollectionNotAvailable(CdcrReplicationDistributedZkTest.java:113)
	at org.apache.solr.cloud.CdcrReplicationDistributedZkTest.doTest(CdcrReplicationDistributedZkTest.java:42)
	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:960)
	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:935)
	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)




Build Log:
[...truncated 10388 lines...]
   [junit4] Suite: org.apache.solr.cloud.CdcrReplicationDistributedZkTest
   [junit4]   2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/init-core-data-001
   [junit4]   2> 2094161 T13726 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
   [junit4]   2> 2094162 T13726 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 2094177 T13726 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 2094178 T13727 oasc.ZkTestServer$2$1.setClientPort client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 2094179 T13727 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 2094279 T13726 oasc.ZkTestServer.run start zk server on port:58368
   [junit4]   2> 2094316 T13726 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig-cdcr.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 2094326 T13726 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
   [junit4]   2> 2094334 T13726 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 2094344 T13726 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 2094350 T13726 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 2094357 T13726 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 2094362 T13726 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 2094410 T13726 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 2094415 T13726 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 2094421 T13726 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 2094428 T13726 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 2094434 T13726 oas.SolrTestCaseJ4.setUp ###Starting doTest
   [junit4]   2> 2095194 T13726 oas.SolrTestCaseJ4.writeCoreProperties Writing core.properties file to /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-001/cores/collection1
   [junit4]   2> 2095201 T13726 oejs.Server.doStart jetty-9.2.10.v20150310
   [junit4]   2> 2095206 T13726 oejsh.ContextHandler.doStart Started o.e.j.s.ServletContextHandler@5b7dea47{/,null,AVAILABLE}
   [junit4]   2> 2095206 T13726 oejs.AbstractConnector.doStart Started ServerConnector@6e705ea1{HTTP/1.1}{127.0.0.1:58372}
   [junit4]   2> 2095207 T13726 oejs.Server.doStart Started @2096758ms
   [junit4]   2> 2095207 T13726 oascse.JettySolrRunner$1.lifeCycleStarted Jetty properties: {shards=shard1, hostContext=/, hostPort=58372, coreRootDirectory=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-001/cores}
   [junit4]   2> 2095208 T13726 oass.SolrDispatchFilter.init SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@74a14482
   [junit4]   2> 2095208 T13726 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-001/'
   [junit4]   2> 2095270 T13726 oasc.SolrXmlConfig.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-001/solr.xml
   [junit4]   2> 2095282 T13726 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-001/cores
   [junit4]   2> 2095283 T13726 oasc.CoreContainer.<init> New CoreContainer 1971941645
   [junit4]   2> 2095283 T13726 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-001/]
   [junit4]   2> 2095284 T13726 oasc.CoreContainer.load loading shared library: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-001/lib
   [junit4]   2> 2095284 T13726 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: lib (resolved as: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-001/lib).
   [junit4]   2> 2095298 T13726 oashc.HttpShardHandlerFactory.init 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> 2095307 T13726 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 2095308 T13726 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 2095309 T13726 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 2095309 T13726 oasc.CoreContainer.load Node Name: 127.0.0.1
   [junit4]   2> 2095309 T13726 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:58368/solr
   [junit4]   2> 2095310 T13726 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2095366 T13726 n:127.0.0.1:58372_ oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58372_
   [junit4]   2> 2095390 T13726 n:127.0.0.1:58372_ oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 2095393 T13726 n:127.0.0.1:58372_ oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:58372_
   [junit4]   2> 2095397 T13726 n:127.0.0.1:58372_ oasc.Overseer.start Overseer (id=93873548712280067-127.0.0.1:58372_-n_0000000000) starting
   [junit4]   2> 2095419 T13726 n:127.0.0.1:58372_ oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
   [junit4]   2> 2095423 T13756 n:127.0.0.1:58372_ oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 2095425 T13755 n:127.0.0.1:58372_ oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 2095438 T13726 n:127.0.0.1:58372_ oasc.CoreContainer.initializeAuthenticationPlugin No authentication plugin used.
   [junit4]   2> 2095439 T13726 n:127.0.0.1:58372_ oasc.CoreContainer.intializeAuthorizationPlugin Security conf doesn't exist. Skipping setup for authorization module.
   [junit4]   2> 2095443 T13726 n:127.0.0.1:58372_ oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-001/cores
   [junit4]   2> 2095445 T13726 n:127.0.0.1:58372_ oasc.CoreDescriptor.<init> CORE DESCRIPTOR: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, instanceDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-001/cores/collection1, collection=tmp_collection, absoluteInstDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-001/cores/collection1/, coreNodeName=, dataDir=data/, shard=}
   [junit4]   2> 2095446 T13726 n:127.0.0.1:58372_ oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-001/cores/collection1/
   [junit4]   2> 2095446 T13726 n:127.0.0.1:58372_ oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 2095448 T13758 n:127.0.0.1:58372_ c:tmp_collection x:collection1 oasc.ZkController.publish publishing core=collection1 state=down collection=tmp_collection
   [junit4]   2> 2095449 T13758 n:127.0.0.1:58372_ c:tmp_collection x:collection1 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2095450 T13754 n:127.0.0.1:58372_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 2095450 T13758 n:127.0.0.1:58372_ oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 2095452 T13755 n:127.0.0.1:58372_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58372",
   [junit4]   2> 	  "node_name":"127.0.0.1:58372_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"tmp_collection",
   [junit4]   2> 	  "operation":"state"} current state version: 0
   [junit4]   2> 2095453 T13755 n:127.0.0.1:58372_ oasco.ReplicaMutator.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58372",
   [junit4]   2> 	  "node_name":"127.0.0.1:58372_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"tmp_collection",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 2095453 T13755 n:127.0.0.1:58372_ oasco.ClusterStateMutator.createCollection building a new cName: tmp_collection
   [junit4]   2> 2095454 T13755 n:127.0.0.1:58372_ oasco.ReplicaMutator.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 2096452 T13758 n:127.0.0.1:58372_ oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 2096453 T13758 n:127.0.0.1:58372_ oasc.ZkController.createCollectionZkNode Check for collection zkNode:tmp_collection
   [junit4]   2> 2096454 T13758 n:127.0.0.1:58372_ oasc.ZkController.createCollectionZkNode Creating collection in ZooKeeper:tmp_collection
   [junit4]   2> 2096454 T13758 n:127.0.0.1:58372_ oasc.ZkController.getConfName Looking for collection configName
   [junit4]   2> 2096456 T13758 n:127.0.0.1:58372_ oasc.ZkController.getConfName Only one config set found in zk - using it:conf1
   [junit4]   2> 2096460 T13758 n:127.0.0.1:58372_ oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-001/cores/collection1/'
   [junit4]   2> 2096486 T13758 n:127.0.0.1:58372_ oasc.Config.<init> loaded config solrconfig.xml with version 0 
   [junit4]   2> 2096496 T13758 n:127.0.0.1:58372_ oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
   [junit4]   2> 2096502 T13758 n:127.0.0.1:58372_ oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 2096515 T13758 n:127.0.0.1:58372_ oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 2096519 T13758 n:127.0.0.1:58372_ oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 2096530 T13758 n:127.0.0.1:58372_ oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 2096653 T13758 n:127.0.0.1:58372_ oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2096656 T13758 n:127.0.0.1:58372_ oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2096656 T13758 n:127.0.0.1:58372_ oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2096659 T13758 n:127.0.0.1:58372_ oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2096703 T13758 n:127.0.0.1:58372_ oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection tmp_collection
   [junit4]   2> 2096703 T13758 n:127.0.0.1:58372_ x:collection1 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 2096704 T13758 n:127.0.0.1:58372_ x:collection1 oasc.SolrCore.<init> [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-001/cores/collection1/], dataDir=[null]
   [junit4]   2> 2096704 T13758 n:127.0.0.1:58372_ x:collection1 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@e679ea3
   [junit4]   2> 2096705 T13758 n:127.0.0.1:58372_ x:collection1 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-001/cores/collection1/data
   [junit4]   2> 2096705 T13758 n:127.0.0.1:58372_ x:collection1 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-001/cores/collection1/data/index/
   [junit4]   2> 2096705 T13758 n:127.0.0.1:58372_ x:collection1 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-001/cores/collection1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 2096706 T13758 n:127.0.0.1:58372_ x:collection1 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-001/cores/collection1/data/index
   [junit4]   2> 2096706 T13758 n:127.0.0.1:58372_ x:collection1 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=28, maxMergeAtOnceExplicit=22, maxMergedSegmentMB=7.724609375, floorSegmentMB=1.0654296875, forceMergeDeletesPctAllowed=13.298767754264684, segmentsPerTier=26.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 2096706 T13758 n:127.0.0.1:58372_ x:collection1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@3a20c44e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3a1df9db),segFN=segments_1,generation=1}
   [junit4]   2> 2096708 T13758 n:127.0.0.1:58372_ x:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2096714 T13758 n:127.0.0.1:58372_ x:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "cdcr-processor-chain"
   [junit4]   2> 2096715 T13758 n:127.0.0.1:58372_ x:collection1 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 2096722 T13758 n:127.0.0.1:58372_ x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2096725 T13758 n:127.0.0.1:58372_ x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2096727 T13758 n:127.0.0.1:58372_ x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2096728 T13758 n:127.0.0.1:58372_ x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2096728 T13758 n:127.0.0.1:58372_ x:collection1 oasc.PluginBag.createPlugin requestHandler : '/replication' created with startup=lazy 
   [junit4]   2> 2096732 T13758 n:127.0.0.1:58372_ x:collection1 oasc.SolrResourceLoader.findClass WARN Solr loaded a deprecated plugin/analysis class [org.apache.solr.handler.admin.AdminHandlers]. Please consult documentation how to replace it accordingly.
   [junit4]   2> 2096733 T13758 n:127.0.0.1:58372_ x:collection1 oasc.SolrResourceLoader.findClass WARN Solr loaded a deprecated plugin/analysis class [org.apache.solr.handler.admin.AdminHandlers]. Please consult documentation how to replace it accordingly.
   [junit4]   2> 2096733 T13758 n:127.0.0.1:58372_ x:collection1 oasc.RequestHandlers.initHandlersFromConfig 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,/admin/threads,/admin/ping,/cdcr,/update,/admin/file
   [junit4]   2> 2096734 T13758 n:127.0.0.1:58372_ x:collection1 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 2096735 T13758 n:127.0.0.1:58372_ x:collection1 oasu.UpdateHandler.<init> Using UpdateLog implementation: org.apache.solr.update.CdcrUpdateLog
   [junit4]   2> 2096736 T13758 n:127.0.0.1:58372_ x:collection1 oasu.UpdateLog.init Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 2096737 T13758 n:127.0.0.1:58372_ x:collection1 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 2096737 T13758 n:127.0.0.1:58372_ x:collection1 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 2096738 T13758 n:127.0.0.1:58372_ x:collection1 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=32, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 2096738 T13758 n:127.0.0.1:58372_ x:collection1 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@3a20c44e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3a1df9db),segFN=segments_1,generation=1}
   [junit4]   2> 2096738 T13758 n:127.0.0.1:58372_ x:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2096739 T13758 n:127.0.0.1:58372_ x:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@cceeb31[collection1] main
   [junit4]   2> 2096739 T13758 n:127.0.0.1:58372_ x:collection1 oasu.UpdateLog.onFirstSearcher On first searcher opened, looking up max value of version field
   [junit4]   2> 2096739 T13758 n:127.0.0.1:58372_ x:collection1 oasu.VersionInfo.getMaxVersionFromIndex Refreshing highest value of _version_ for 65536 version buckets from index
   [junit4]   2> 2096739 T13758 n:127.0.0.1:58372_ x:collection1 oasu.VersionInfo.getMaxVersionFromIndex WARN No terms found for _version_, cannot seed version bucket highest value from index
   [junit4]   2> 2096740 T13758 n:127.0.0.1:58372_ x:collection1 oasu.UpdateLog.seedBucketsWithHighestVersion WARN Could not find max version in index or recent updates, using new clock 1501976782077689856
   [junit4]   2> 2096742 T13758 n:127.0.0.1:58372_ x:collection1 oasu.UpdateLog.seedBucketsWithHighestVersion Took 3 ms to seed version buckets with highest version 1501976782077689856
   [junit4]   2> 2096744 T13758 n:127.0.0.1:58372_ x:collection1 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 2096746 T13758 n:127.0.0.1:58372_ x:collection1 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 2096746 T13758 n:127.0.0.1:58372_ x:collection1 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 2096746 T13758 n:127.0.0.1:58372_ x:collection1 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2096747 T13758 n:127.0.0.1:58372_ x:collection1 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 2096747 T13758 n:127.0.0.1:58372_ x:collection1 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2096748 T13758 n:127.0.0.1:58372_ x:collection1 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 2096755 T13758 n:127.0.0.1:58372_ x:collection1 oash.CdcrBufferStateManager.createStateNode Created znode /collections/tmp_collection/cdcr/state/buffer
   [junit4]   2> 2096759 T13758 n:127.0.0.1:58372_ x:collection1 oash.CdcrProcessStateManager.createStateNode Created znode /collections/tmp_collection/cdcr/state/process
   [junit4]   2> 2096767 T13758 n:127.0.0.1:58372_ x:collection1 oasha.AdminHandlers.inform WARN <requestHandler name="/admin/" 
   [junit4]   2> 	 class="solr.admin.AdminHandlers" /> is deprecated . It is not required anymore
   [junit4]   2> 2096767 T13759 n:127.0.0.1:58372_ x:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@cceeb31[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2096768 T13758 n:127.0.0.1:58372_ x:collection1 oasc.ZkController.getConfDirListeners watch zkdir /configs/conf1
   [junit4]   2> 2096769 T13758 n:127.0.0.1:58372_ x:collection1 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 2096772 T13763 n:127.0.0.1:58372_ c:tmp_collection s:shard2 x:collection1 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58372 collection:tmp_collection shard:shard2
   [junit4]   2> 2096773 T13726 n:127.0.0.1:58372_ oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1
   [junit4]   2> 2096773 T13726 n:127.0.0.1:58372_ oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 2096788 T13763 n:127.0.0.1:58372_ c:tmp_collection s:shard2 x:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 2096792 T13754 n:127.0.0.1:58372_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 2096795 T13763 n:127.0.0.1:58372_ c:tmp_collection s:shard2 x:collection1 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 2096796 T13763 n:127.0.0.1:58372_ c:tmp_collection s:shard2 x:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C4820 name=collection1 org.apache.solr.core.SolrCore@575dd8b1 url=http://127.0.0.1:58372/collection1 node=127.0.0.1:58372_ C4820_STATE=coll:tmp_collection core:collection1 props:{core=collection1, base_url=http://127.0.0.1:58372, node_name=127.0.0.1:58372_, state=down}
   [junit4]   2> 2096796 T13763 n:127.0.0.1:58372_ c:tmp_collection s:shard2 x:collection1 C4820 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58372/collection1/
   [junit4]   2> 2096796 T13763 n:127.0.0.1:58372_ c:tmp_collection s:shard2 x:collection1 C4820 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 2096796 T13763 n:127.0.0.1:58372_ c:tmp_collection s:shard2 x:collection1 C4820 oasc.SyncStrategy.syncToMe http://127.0.0.1:58372/collection1/ has no replicas
   [junit4]   2> 2096796 T13763 n:127.0.0.1:58372_ c:tmp_collection s:shard2 x:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58372/collection1/ shard2
   [junit4]   2> 2096796 T13755 n:127.0.0.1:58372_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"tmp_collection"} current state version: 1
   [junit4]   2> 2096811 T13754 n:127.0.0.1:58372_ oash.CdcrLeaderStateManager$LeaderStateWatcher.process Received new leader state @ tmp_collection:shard2
   [junit4]   2> 2096821 T13754 n:127.0.0.1:58372_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 2096826 T13755 n:127.0.0.1:58372_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"tmp_collection",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58372",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "state":"active"} current state version: 1
   [junit4]   2> 2096979 T13763 n:127.0.0.1:58372_ c:tmp_collection s:shard2 x:collection1 oasc.ZkController.register We are http://127.0.0.1:58372/collection1/ and leader is http://127.0.0.1:58372/collection1/
   [junit4]   2> 2096980 T13763 n:127.0.0.1:58372_ c:tmp_collection s:shard2 x:collection1 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58372
   [junit4]   2> 2096980 T13763 n:127.0.0.1:58372_ c:tmp_collection s:shard2 x:collection1 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 2096980 T13763 n:127.0.0.1:58372_ c:tmp_collection s:shard2 x:collection1 oasc.ZkController.publish publishing core=collection1 state=active collection=tmp_collection
   [junit4]   2> 2096980 T13763 n:127.0.0.1:58372_ c:tmp_collection s:shard2 x:collection1 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2096985 T13754 n:127.0.0.1:58372_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 2096991 T13755 n:127.0.0.1:58372_ oasc.Overseer$ClusterStateUpdater.run 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:58372",
   [junit4]   2> 	  "node_name":"127.0.0.1:58372_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"tmp_collection",
   [junit4]   2> 	  "operation":"state"} current state version: 2
   [junit4]   2> 2096995 T13755 n:127.0.0.1:58372_ oasco.ReplicaMutator.updateState Update state numShards=2 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:58372",
   [junit4]   2> 	  "node_name":"127.0.0.1:58372_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"tmp_collection",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 2097321 T13726 oas.SolrTestCaseJ4.writeCoreProperties Writing core.properties file to /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-002/cores/collection1
   [junit4]   2> 2097330 T13726 oejs.Server.doStart jetty-9.2.10.v20150310
   [junit4]   2> 2097360 T13726 oejsh.ContextHandler.doStart Started o.e.j.s.ServletContextHandler@1cdbfea0{/,null,AVAILABLE}
   [junit4]   2> 2097361 T13726 oejs.AbstractConnector.doStart Started ServerConnector@53ac2412{HTTP/1.1}{127.0.0.1:58377}
   [junit4]   2> 2097361 T13726 oejs.Server.doStart Started @2098912ms
   [junit4]   2> 2097362 T13726 oascse.JettySolrRunner$1.lifeCycleStarted Jetty properties: {shards=shard2, hostContext=/, hostPort=58377, coreRootDirectory=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-002/cores}
   [junit4]   2> 2097362 T13726 oass.SolrDispatchFilter.init SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@74a14482
   [junit4]   2> 2097363 T13726 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-002/'
   [junit4]   2> 2097414 T13726 oasc.SolrXmlConfig.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-002/solr.xml
   [junit4]   2> 2097435 T13726 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-002/cores
   [junit4]   2> 2097436 T13726 oasc.CoreContainer.<init> New CoreContainer 2069112438
   [junit4]   2> 2097436 T13726 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-002/]
   [junit4]   2> 2097436 T13726 oasc.CoreContainer.load loading shared library: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-002/lib
   [junit4]   2> 2097437 T13726 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: lib (resolved as: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-002/lib).
   [junit4]   2> 2097452 T13726 oashc.HttpShardHandlerFactory.init 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> 2097456 T13726 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 2097457 T13726 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 2097457 T13726 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 2097458 T13726 oasc.CoreContainer.load Node Name: 127.0.0.1
   [junit4]   2> 2097458 T13726 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:58368/solr
   [junit4]   2> 2097459 T13726 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2098504 T13726 n:127.0.0.1:58377_ oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58377_
   [junit4]   2> 2098516 T13726 n:127.0.0.1:58377_ oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 2098520 T13726 n:127.0.0.1:58377_ oasc.CoreContainer.initializeAuthenticationPlugin No authentication plugin used.
   [junit4]   2> 2098521 T13726 n:127.0.0.1:58377_ oasc.CoreContainer.intializeAuthorizationPlugin Security conf doesn't exist. Skipping setup for authorization module.
   [junit4]   2> 2098522 T13726 n:127.0.0.1:58377_ oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-002/cores
   [junit4]   2> 2098523 T13726 n:127.0.0.1:58377_ oasc.CoreDescriptor.<init> CORE DESCRIPTOR: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, instanceDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-002/cores/collection1, collection=tmp_collection, absoluteInstDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-002/cores/collection1/, coreNodeName=, dataDir=data/, shard=}
   [junit4]   2> 2098524 T13726 n:127.0.0.1:58377_ oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-002/cores/collection1/
   [junit4]   2> 2098524 T13726 n:127.0.0.1:58377_ oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 2098525 T13781 n:127.0.0.1:58377_ c:tmp_collection x:collection1 oasc.ZkController.publish publishing core=collection1 state=down collection=tmp_collection
   [junit4]   2> 2098526 T13781 n:127.0.0.1:58377_ c:tmp_collection x:collection1 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2098527 T13781 n:127.0.0.1:58377_ oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 2098527 T13754 n:127.0.0.1:58372_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 2098529 T13755 n:127.0.0.1:58372_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58377",
   [junit4]   2> 	  "node_name":"127.0.0.1:58377_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"tmp_collection",
   [junit4]   2> 	  "operation":"state"} current state version: 3
   [junit4]   2> 2098531 T13755 n:127.0.0.1:58372_ oasco.ReplicaMutator.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58377",
   [junit4]   2> 	  "node_name":"127.0.0.1:58377_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"tmp_collection",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 2098532 T13755 n:127.0.0.1:58372_ oasco.ReplicaMutator.updateState Collection already exists with numShards=2
   [junit4]   2> 2098532 T13755 n:127.0.0.1:58372_ oasco.ReplicaMutator.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 2099529 T13781 n:127.0.0.1:58377_ oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 2099529 T13781 n:127.0.0.1:58377_ oasc.ZkController.createCollectionZkNode Check for collection zkNode:tmp_collection
   [junit4]   2> 2099530 T13781 n:127.0.0.1:58377_ oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 2099532 T13781 n:127.0.0.1:58377_ oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-002/cores/collection1/'
   [junit4]   2> 2099551 T13781 n:127.0.0.1:58377_ oasc.Config.<init> loaded config solrconfig.xml with version 0 
   [junit4]   2> 2099559 T13781 n:127.0.0.1:58377_ oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
   [junit4]   2> 2099566 T13781 n:127.0.0.1:58377_ oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 2099576 T13781 n:127.0.0.1:58377_ oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 2099578 T13781 n:127.0.0.1:58377_ oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 2099582 T13781 n:127.0.0.1:58377_ oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 2099690 T13781 n:127.0.0.1:58377_ oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2099692 T13781 n:127.0.0.1:58377_ oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2099692 T13781 n:127.0.0.1:58377_ oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2099696 T13781 n:127.0.0.1:58377_ oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2099733 T13781 n:127.0.0.1:58377_ oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection tmp_collection
   [junit4]   2> 2099733 T13781 n:127.0.0.1:58377_ x:collection1 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 2099734 T13781 n:127.0.0.1:58377_ x:collection1 oasc.SolrCore.<init> [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-002/cores/collection1/], dataDir=[null]
   [junit4]   2> 2099734 T13781 n:127.0.0.1:58377_ x:collection1 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@e679ea3
   [junit4]   2> 2099735 T13781 n:127.0.0.1:58377_ x:collection1 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-002/cores/collection1/data
   [junit4]   2> 2099735 T13781 n:127.0.0.1:58377_ x:collection1 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-002/cores/collection1/data/index/
   [junit4]   2> 2099735 T13781 n:127.0.0.1:58377_ x:collection1 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-002/cores/collection1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 2099737 T13781 n:127.0.0.1:58377_ x:collection1 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-002/cores/collection1/data/index
   [junit4]   2> 2099737 T13781 n:127.0.0.1:58377_ x:collection1 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=28, maxMergeAtOnceExplicit=22, maxMergedSegmentMB=7.724609375, floorSegmentMB=1.0654296875, forceMergeDeletesPctAllowed=13.298767754264684, segmentsPerTier=26.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 2099738 T13781 n:127.0.0.1:58377_ x:collection1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@56687b92 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@535eba73),segFN=segments_1,generation=1}
   [junit4]   2> 2099738 T13781 n:127.0.0.1:58377_ x:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2099744 T13781 n:127.0.0.1:58377_ x:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "cdcr-processor-chain"
   [junit4]   2> 2099744 T13781 n:127.0.0.1:58377_ x:collection1 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 2099752 T13781 n:127.0.0.1:58377_ x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2099753 T13781 n:127.0.0.1:58377_ x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2099754 T13781 n:127.0.0.1:58377_ x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2099757 T13781 n:127.0.0.1:58377_ x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2099757 T13781 n:127.0.0.1:58377_ x:collection1 oasc.PluginBag.createPlugin requestHandler : '/replication' created with startup=lazy 
   [junit4]   2> 2099762 T13781 n:127.0.0.1:58377_ x:collection1 oasc.SolrResourceLoader.findClass WARN Solr loaded a deprecated plugin/analysis class [org.apache.solr.handler.admin.AdminHandlers]. Please consult documentation how to replace it accordingly.
   [junit4]   2> 2099762 T13781 n:127.0.0.1:58377_ x:collection1 oasc.SolrResourceLoader.findClass WARN Solr loaded a deprecated plugin/analysis class [org.apache.solr.handler.admin.AdminHandlers]. Please consult documentation how to replace it accordingly.
   [junit4]   2> 2099762 T13781 n:127.0.0.1:58377_ x:collection1 oasc.RequestHandlers.initHandlersFromConfig 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,/admin/threads,/admin/ping,/cdcr,/update,/admin/file
   [junit4]   2> 2099763 T13781 n:127.0.0.1:58377_ x:collection1 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 2099764 T13781 n:127.0.0.1:58377_ x:collection1 oasu.UpdateHandler.<init> Using UpdateLog implementation: org.apache.solr.update.CdcrUpdateLog
   [junit4]   2> 2099765 T13781 n:127.0.0.1:58377_ x:collection1 oasu.UpdateLog.init Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 2099766 T13781 n:127.0.0.1:58377_ x:collection1 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 2099767 T13781 n:127.0.0.1:58377_ x:collection1 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 2099768 T13781 n:127.0.0.1:58377_ x:collection1 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=32, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 2099768 T13781 n:127.0.0.1:58377_ x:collection1 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@56687b92 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@535eba73),segFN=segments_1,generation=1}
   [junit4]   2> 2099768 T13781 n:127.0.0.1:58377_ x:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2099769 T13781 n:127.0.0.1:58377_ x:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@28a4a399[collection1] main
   [junit4]   2> 2099769 T13781 n:127.0.0.1:58377_ x:collection1 oasu.UpdateLog.onFirstSearcher On first searcher opened, looking up max value of version field
   [junit4]   2> 2099769 T13781 n:127.0.0.1:58377_ x:collection1 oasu.VersionInfo.getMaxVersionFromIndex Refreshing highest value of _version_ for 65536 version buckets from index
   [junit4]   2> 2099769 T13781 n:127.0.0.1:58377_ x:collection1 oasu.VersionInfo.getMaxVersionFromIndex WARN No terms found for _version_, cannot seed version bucket highest value from index
   [junit4]   2> 2099769 T13781 n:127.0.0.1:58377_ x:collection1 oasu.UpdateLog.seedBucketsWithHighestVersion WARN Could not find max version in index or recent updates, using new clock 1501976785253826560
   [junit4]   2> 2099771 T13781 n:127.0.0.1:58377_ x:collection1 oasu.UpdateLog.seedBucketsWithHighestVersion Took 2 ms to seed version buckets with highest version 1501976785253826560
   [junit4]   2> 2099773 T13781 n:127.0.0.1:58377_ x:collection1 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 2099774 T13781 n:127.0.0.1:58377_ x:collection1 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 2099774 T13781 n:127.0.0.1:58377_ x:collection1 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 2099774 T13781 n:127.0.0.1:58377_ x:collection1 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2099775 T13781 n:127.0.0.1:58377_ x:collection1 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 2099776 T13781 n:127.0.0.1:58377_ x:collection1 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2099776 T13781 n:127.0.0.1:58377_ x:collection1 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 2099782 T13781 n:127.0.0.1:58377_ x:collection1 oasha.AdminHandlers.inform WARN <requestHandler name="/admin/" 
   [junit4]   2> 	 class="solr.admin.AdminHandlers" /> is deprecated . It is not required anymore
   [junit4]   2> 2099783 T13782 n:127.0.0.1:58377_ x:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@28a4a399[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2099784 T13781 n:127.0.0.1:58377_ x:collection1 oasc.ZkController.getConfDirListeners watch zkdir /configs/conf1
   [junit4]   2> 2099785 T13781 n:127.0.0.1:58377_ x:collection1 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 2099786 T13786 n:127.0.0.1:58377_ c:tmp_collection s:shard1 x:collection1 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58377 collection:tmp_collection shard:shard1
   [junit4]   2> 2099787 T13726 n:127.0.0.1:58377_ oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1
   [junit4]   2> 2099788 T13726 n:127.0.0.1:58377_ oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 2099802 T13786 n:127.0.0.1:58377_ c:tmp_collection s:shard1 x:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 2099807 T13754 n:127.0.0.1:58372_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 2099808 T13786 n:127.0.0.1:58377_ c:tmp_collection s:shard1 x:collection1 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 2099808 T13786 n:127.0.0.1:58377_ c:tmp_collection s:shard1 x:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C4821 name=collection1 org.apache.solr.core.SolrCore@6e4c0b73 url=http://127.0.0.1:58377/collection1 node=127.0.0.1:58377_ C4821_STATE=coll:tmp_collection core:collection1 props:{core=collection1, base_url=http://127.0.0.1:58377, node_name=127.0.0.1:58377_, state=down}
   [junit4]   2> 2099808 T13786 n:127.0.0.1:58377_ c:tmp_collection s:shard1 x:collection1 C4821 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58377/collection1/
   [junit4]   2> 2099809 T13786 n:127.0.0.1:58377_ c:tmp_collection s:shard1 x:collection1 C4821 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 2099809 T13786 n:127.0.0.1:58377_ c:tmp_collection s:shard1 x:collection1 C4821 oasc.SyncStrategy.syncToMe http://127.0.0.1:58377/collection1/ has no replicas
   [junit4]   2> 2099810 T13786 n:127.0.0.1:58377_ c:tmp_collection s:shard1 x:collection1 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58377/collection1/ shard1
   [junit4]   2> 2099809 T13755 n:127.0.0.1:58372_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"tmp_collection"} current state version: 4
   [junit4]   2> 2099817 T13780 n:127.0.0.1:58377_ oash.CdcrLeaderStateManager$LeaderStateWatcher.process Received new leader state @ tmp_collection:shard1
   [junit4]   2> 2099823 T13754 n:127.0.0.1:58372_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 2099826 T13755 n:127.0.0.1:58372_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"tmp_collection",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58377",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "state":"active"} current state version: 4
   [junit4]   2> 2099979 T13786 n:127.0.0.1:58377_ c:tmp_collection s:shard1 x:collection1 oasc.ZkController.register We are http://127.0.0.1:58377/collection1/ and leader is http://127.0.0.1:58377/collection1/
   [junit4]   2> 2099979 T13786 n:127.0.0.1:58377_ c:tmp_collection s:shard1 x:collection1 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58377
   [junit4]   2> 2099980 T13786 n:127.0.0.1:58377_ c:tmp_collection s:shard1 x:collection1 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 2099980 T13786 n:127.0.0.1:58377_ c:tmp_collection s:shard1 x:collection1 oasc.ZkController.publish publishing core=collection1 state=active collection=tmp_collection
   [junit4]   2> 2099980 T13786 n:127.0.0.1:58377_ c:tmp_collection s:shard1 x:collection1 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2099983 T13754 n:127.0.0.1:58372_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 2099987 T13755 n:127.0.0.1:58372_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58377",
   [junit4]   2> 	  "node_name":"127.0.0.1:58377_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"tmp_collection",
   [junit4]   2> 	  "operation":"state"} current state version: 5
   [junit4]   2> 2099990 T13755 n:127.0.0.1:58372_ oasco.ReplicaMutator.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58377",
   [junit4]   2> 	  "node_name":"127.0.0.1:58377_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"tmp_collection",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 2100300 T13726 oas.SolrTestCaseJ4.writeCoreProperties Writing core.properties file to /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-003/cores/collection1
   [junit4]   2> 2100304 T13726 oejs.Server.doStart jetty-9.2.10.v20150310
   [junit4]   2> 2100307 T13726 oejsh.ContextHandler.doStart Started o.e.j.s.ServletContextHandler@629301c{/,null,AVAILABLE}
   [junit4]   2> 2100308 T13726 oejs.AbstractConnector.doStart Started ServerConnector@1e544478{HTTP/1.1}{127.0.0.1:58384}
   [junit4]   2> 2100308 T13726 oejs.Server.doStart Started @2101857ms
   [junit4]   2> 2100308 T13726 oascse.JettySolrRunner$1.lifeCycleStarted Jetty properties: {shards=shard3, hostContext=/, hostPort=58384, coreRootDirectory=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-003/cores}
   [junit4]   2> 2100309 T13726 oass.SolrDispatchFilter.init SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@74a14482
   [junit4]   2> 2100309 T13726 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-003/'
   [junit4]   2> 2100368 T13726 oasc.SolrXmlConfig.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-003/solr.xml
   [junit4]   2> 2100382 T13726 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-003/cores
   [junit4]   2> 2100383 T13726 oasc.CoreContainer.<init> New CoreContainer 147184432
   [junit4]   2> 2100383 T13726 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-003/]
   [junit4]   2> 2100383 T13726 oasc.CoreContainer.load loading shared library: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-003/lib
   [junit4]   2> 2100384 T13726 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: lib (resolved as: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-003/lib).
   [junit4]   2> 2100393 T13726 oashc.HttpShardHandlerFactory.init 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> 2100397 T13726 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 2100398 T13726 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 2100398 T13726 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 2100399 T13726 oasc.CoreContainer.load Node Name: 127.0.0.1
   [junit4]   2> 2100399 T13726 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:58368/solr
   [junit4]   2> 2100400 T13726 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2101443 T13726 n:127.0.0.1:58384_ oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58384_
   [junit4]   2> 2101453 T13726 n:127.0.0.1:58384_ oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 2101456 T13726 n:127.0.0.1:58384_ oasc.CoreContainer.initializeAuthenticationPlugin No authentication plugin used.
   [junit4]   2> 2101457 T13726 n:127.0.0.1:58384_ oasc.CoreContainer.intializeAuthorizationPlugin Security conf doesn't exist. Skipping setup for authorization module.
   [junit4]   2> 2101460 T13726 n:127.0.0.1:58384_ oasc.CorePropertiesLocator.discover Looking for core definitions underneath /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-003/cores
   [junit4]   2> 2101462 T13726 n:127.0.0.1:58384_ oasc.CoreDescriptor.<init> CORE DESCRIPTOR: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, instanceDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-003/cores/collection1, collection=tmp_collection, absoluteInstDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-003/cores/collection1/, coreNodeName=, dataDir=data/, shard=}
   [junit4]   2> 2101462 T13726 n:127.0.0.1:58384_ oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-003/cores/collection1/
   [junit4]   2> 2101462 T13726 n:127.0.0.1:58384_ oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 2101464 T13804 n:127.0.0.1:58384_ c:tmp_collection x:collection1 oasc.ZkController.publish publishing core=collection1 state=down collection=tmp_collection
   [junit4]   2> 2101465 T13804 n:127.0.0.1:58384_ c:tmp_collection x:collection1 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2101466 T13754 n:127.0.0.1:58372_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 2101466 T13804 n:127.0.0.1:58384_ oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 2101467 T13755 n:127.0.0.1:58372_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58384",
   [junit4]   2> 	  "node_name":"127.0.0.1:58384_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"tmp_collection",
   [junit4]   2> 	  "operation":"state"} current state version: 6
   [junit4]   2> 2101468 T13755 n:127.0.0.1:58372_ oasco.ReplicaMutator.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58384",
   [junit4]   2> 	  "node_name":"127.0.0.1:58384_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"tmp_collection",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 2101469 T13755 n:127.0.0.1:58372_ oasco.ReplicaMutator.updateState Collection already exists with numShards=2
   [junit4]   2> 2101469 T13755 n:127.0.0.1:58372_ oasco.ReplicaMutator.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 2102468 T13804 n:127.0.0.1:58384_ oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 2102468 T13804 n:127.0.0.1:58384_ oasc.ZkController.createCollectionZkNode Check for collection zkNode:tmp_collection
   [junit4]   2> 2102469 T13804 n:127.0.0.1:58384_ oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 2102471 T13804 n:127.0.0.1:58384_ oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-003/cores/collection1/'
   [junit4]   2> 2102491 T13804 n:127.0.0.1:58384_ oasc.Config.<init> loaded config solrconfig.xml with version 0 
   [junit4]   2> 2102498 T13804 n:127.0.0.1:58384_ oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
   [junit4]   2> 2102501 T13804 n:127.0.0.1:58384_ oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 2102510 T13804 n:127.0.0.1:58384_ oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 2102512 T13804 n:127.0.0.1:58384_ oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 2102518 T13804 n:127.0.0.1:58384_ oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 2102623 T13804 n:127.0.0.1:58384_ oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2102624 T13804 n:127.0.0.1:58384_ oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2102624 T13804 n:127.0.0.1:58384_ oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2102628 T13804 n:127.0.0.1:58384_ oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2102669 T13804 n:127.0.0.1:58384_ oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection tmp_collection
   [junit4]   2> 2102669 T13804 n:127.0.0.1:58384_ x:collection1 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 2102669 T13804 n:127.0.0.1:58384_ x:collection1 oasc.SolrCore.<init> [[collection1] ] Opening new SolrCore at [/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-003/cores/collection1/], dataDir=[null]
   [junit4]   2> 2102669 T13804 n:127.0.0.1:58384_ x:collection1 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@e679ea3
   [junit4]   2> 2102671 T13804 n:127.0.0.1:58384_ x:collection1 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-003/cores/collection1/data
   [junit4]   2> 2102671 T13804 n:127.0.0.1:58384_ x:collection1 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-003/cores/collection1/data/index/
   [junit4]   2> 2102671 T13804 n:127.0.0.1:58384_ x:collection1 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-003/cores/collection1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 2102672 T13804 n:127.0.0.1:58384_ x:collection1 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-003/cores/collection1/data/index
   [junit4]   2> 2102672 T13804 n:127.0.0.1:58384_ x:collection1 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=28, maxMergeAtOnceExplicit=22, maxMergedSegmentMB=7.724609375, floorSegmentMB=1.0654296875, forceMergeDeletesPctAllowed=13.298767754264684, segmentsPerTier=26.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 2102673 T13804 n:127.0.0.1:58384_ x:collection1 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@38fa0db1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@201a6450),segFN=segments_1,generation=1}
   [junit4]   2> 2102673 T13804 n:127.0.0.1:58384_ x:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2102679 T13804 n:127.0.0.1:58384_ x:collection1 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "cdcr-processor-chain"
   [junit4]   2> 2102680 T13804 n:127.0.0.1:58384_ x:collection1 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 2102686 T13804 n:127.0.0.1:58384_ x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2102692 T13804 n:127.0.0.1:58384_ x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2102694 T13804 n:127.0.0.1:58384_ x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2102695 T13804 n:127.0.0.1:58384_ x:collection1 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2102696 T13804 n:127.0.0.1:58384_ x:collection1 oasc.PluginBag.createPlugin requestHandler : '/replication' created with startup=lazy 
   [junit4]   2> 2102701 T13804 n:127.0.0.1:58384_ x:collection1 oasc.SolrResourceLoader.findClass WARN Solr loaded a deprecated plugin/analysis class [org.apache.solr.handler.admin.AdminHandlers]. Please consult documentation how to replace it accordingly.
   [junit4]   2> 2102701 T13804 n:127.0.0.1:58384_ x:collection1 oasc.SolrResourceLoader.findClass WARN Solr loaded a deprecated plugin/analysis class [org.apache.solr.handler.admin.AdminHandlers]. Please consult documentation how to replace it accordingly.
   [junit4]   2> 2102701 T13804 n:127.0.0.1:58384_ x:collection1 oasc.RequestHandlers.initHandlersFromConfig 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,/admin/threads,/admin/ping,/cdcr,/update,/admin/file
   [junit4]   2> 2102702 T13804 n:127.0.0.1:58384_ x:collection1 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 2102703 T13804 n:127.0.0.1:58384_ x:collection1 oasu.UpdateHandler.<init> Using UpdateLog implementation: org.apache.solr.update.CdcrUpdateLog
   [junit4]   2> 2102704 T13804 n:127.0.0.1:58384_ x:collection1 oasu.UpdateLog.init Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 2102706 T13804 n:127.0.0.1:58384_ x:collection1 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 2102706 T13804 n:127.0.0.1:58384_ x:collection1 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 2102708 T13804 n:127.0.0.1:58384_ x:collection1 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=32, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 2102708 T13804 n:127.0.0.1:58384_ x:collection1 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@38fa0db1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@201a6450),segFN=segments_1,generation=1}
   [junit4]   2> 2102708 T13804 n:127.0.0.1:58384_ x:collection1 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2102709 T13804 n:127.0.0.1:58384_ x:collection1 oass.SolrIndexSearcher.<init> Opening Searcher@72c5c9b2[collection1] main
   [junit4]   2> 2102709 T13804 n:127.0.0.1:58384_ x:collection1 oasu.UpdateLog.onFirstSearcher On first searcher opened, looking up max value of version field
   [junit4]   2> 2102709 T13804 n:127.0.0.1:58384_ x:collection1 oasu.VersionInfo.getMaxVersionFromIndex Refreshing highest value of _version_ for 65536 version buckets from index
   [junit4]   2> 2102709 T13804 n:127.0.0.1:58384_ x:collection1 oasu.VersionInfo.getMaxVersionFromIndex WARN No terms found for _version_, cannot seed version bucket highest value from index
   [junit4]   2> 2102709 T13804 n:127.0.0.1:58384_ x:collection1 oasu.UpdateLog.seedBucketsWithHighestVersion WARN Could not find max version in index or recent updates, using new clock 1501976788336640000
   [junit4]   2> 2102713 T13804 n:127.0.0.1:58384_ x:collection1 oasu.UpdateLog.seedBucketsWithHighestVersion Took 4 ms to seed version buckets with highest version 1501976788336640000
   [junit4]   2> 2102715 T13804 n:127.0.0.1:58384_ x:collection1 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 2102717 T13804 n:127.0.0.1:58384_ x:collection1 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 2102717 T13804 n:127.0.0.1:58384_ x:collection1 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 2102717 T13804 n:127.0.0.1:58384_ x:collection1 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2102718 T13804 n:127.0.0.1:58384_ x:collection1 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 2102718 T13804 n:127.0.0.1:58384_ x:collection1 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2102719 T13804 n:127.0.0.1:58384_ x:collection1 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 2102724 T13804 n:127.0.0.1:58384_ x:collection1 oasha.AdminHandlers.inform WARN <requestHandler name="/admin/" 
   [junit4]   2> 	 class="solr.admin.AdminHandlers" /> is deprecated . It is not required anymore
   [junit4]   2> 2102725 T13805 n:127.0.0.1:58384_ x:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@72c5c9b2[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2102725 T13804 n:127.0.0.1:58384_ x:collection1 oasc.ZkController.getConfDirListeners watch zkdir /configs/conf1
   [junit4]   2> 2102726 T13804 n:127.0.0.1:58384_ x:collection1 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 2102729 T13808 n:127.0.0.1:58384_ c:tmp_collection s:shard2 x:collection1 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58384 collection:tmp_collection shard:shard2
   [junit4]   2> 2102730 T13726 n:127.0.0.1:58384_ oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1
   [junit4]   2> 2102731 T13726 n:127.0.0.1:58384_ oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 2102735 T13808 n:127.0.0.1:58384_ c:tmp_collection s:shard2 x:collection1 oasc.ZkController.register We are http://127.0.0.1:58384/collection1/ and leader is http://127.0.0.1:58372/collection1/
   [junit4]   2> 2102735 T13808 n:127.0.0.1:58384_ c:tmp_collection s:shard2 x:collection1 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58384
   [junit4]   2> 2102735 T13808 n:127.0.0.1:58384_ c:tmp_collection s:shard2 x:collection1 oasc.ZkController.checkRecovery Core needs to recover:collection1
   [junit4]   2> 2102735 T13808 n:127.0.0.1:58384_ c:tmp_collection s:shard2 x:collection1 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
   [junit4]   2> ASYNC  NEW_CORE C4822 name=collection1 org.apache.solr.core.SolrCore@5dd27c36 url=http://127.0.0.1:58384/collection1 node=127.0.0.1:58384_ C4822_STATE=coll:tmp_collection core:collection1 props:{core=collection1, base_url=http://127.0.0.1:58384, node_name=127.0.0.1:58384_, state=down}
   [junit4]   2> 2102736 T13809 n:127.0.0.1:58384_ c:tmp_collection s:shard2 x:collection1 C4822 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
   [junit4]   2> 2102738 T13809 n:127.0.0.1:58384_ c:tmp_collection s:shard2 x:collection1 C4822 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
   [junit4]   2> 2102739 T13809 n:127.0.0.1:58384_ c:tmp_collection s:shard2 x:collection1 C4822 oasc.RecoveryStrategy.doRecovery Publishing state of core collection1 as recovering, leader is http://127.0.0.1:58372/collection1/ and I am http://127.0.0.1:58384/collection1/
   [junit4]   2> 2102739 T13809 n:127.0.0.1:58384_ c:tmp_collection s:shard2 x:collection1 C4822 oasc.ZkController.publish publishing core=collection1 state=recovering collection=tmp_collection
   [junit4]   2> 2102739 T13809 n:127.0.0.1:58384_ c:tmp_collection s:shard2 x:collection1 C4822 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2102743 T13754 n:127.0.0.1:58372_ oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 2102749 T13809 n:127.0.0.1:58384_ c:tmp_collection s:shard2 x:collection1 C4822 oasc.RecoveryStrategy.sendPrepRecoveryCmd Sending prep recovery command to http://127.0.0.1:58372; WaitForState: action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1%3A58384_&coreNodeName=core_node3&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true
   [junit4]   2> 2102750 T13755 n:127.0.0.1:58372_ oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node3",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58384",
   [junit4]   2> 	  "node_name":"127.0.0.1:58384_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"recovering",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"tmp_collection",
   [junit4]   2> 	  "operation":"state"} current state version: 7
   [junit4]   2> 2102751 T13755 n:127.0.0.1:58372_ oasco.ReplicaMutator.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node3",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58384",
   [junit4]   2> 	  "node_name":"127.0.0.1:58384_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"recovering",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"tmp_collection",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 2102754 T13744 n:127.0.0.1:58372_ oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
   [junit4]   2> 2102762 T13744 n:127.0.0.1:58372_ oasha.CoreAdminHandler.handleWaitForStateAction Will wait a max of 183 seconds to see collection1 (shard2 of tmp_collection) have state: recovering
   [junit4]   2> 2102762 T13744 n:127.0.0.1:58372_ oasha.CoreAdminHandler.handleWaitForStateAction In WaitForState(recovering): collection=tmp_collection, shard=shard2, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:58384_, coreNodeName=core_node3, onlyIfActiveCheckResult=false, nodeProps: core_node3:{"core":"collection1","base_url":"http://127.0.0.1:58384","node_name":"127.0.0.1:58384_","state":"down"}
   [junit4]   2> 2103229 T13726 oas.SolrTestCaseJ4.writeCoreProperties Writing core.properties file to /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-004/cores/collection1
   [junit4]   2> 2103234 T13726 oejs.Server.doStart jetty-9.2.10.v20150310
   [junit4]   2> 2103239 T13726 oejsh.ContextHandler.doStart Started o.e.j.s.ServletContextHandler@6d9bc843{/,null,AVAILABLE}
   [junit4]   2> 2103239 T13726 oejs.AbstractConnector.doStart Started ServerConnector@72ee53b5{HTTP/1.1}{127.0.0.1:58391}
   [junit4]   2> 2103240 T13726 oejs.Server.doStart Started @2104787ms
   [junit4]   2> 2103240 T13726 oascse.JettySolrRunner$1.lifeCycleStarted Jetty properties: {shards=shard4, hostContext=/, hostPort=58391, coreRootDirectory=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-004/cores}
   [junit4]   2> 2103242 T13726 oass.SolrDispatchFilter.init SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@74a14482
   [junit4]   2> 2103242 T13726 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-004/'
   [junit4]   2> 2103286 T13726 oasc.SolrXmlConfig.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZkTest B073F48B42910119-001/jetty-004/solr.xml
   [junit4]   2> 2103319 T13726 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J1/temp/solr.cloud.CdcrReplicationDistributedZk

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

dRunner.java:792)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
   [junit4]   2> 	        at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	        at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	        at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
   [junit4]   2> 	        at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
   [junit4]   2> 	        at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
   [junit4]   2> 	        at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene50): {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=ja, timezone=Asia/Thimphu
   [junit4]   2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.8.0_45 (64-bit)/cpus=3,threads=4,free=457391840,total=518979584
   [junit4]   2> NOTE: All tests run in this JVM: [TestXIncludeConfig, TestDistributedSearch, TestSweetSpotSimilarityFactory, SSLMigrationTest, TestCSVLoader, TestChildDocTransformer, TestReplicaProperties, TestSolrQueryParserDefaultOperatorResource, QueryResultKeyTest, SimpleMLTQParserTest, SliceStateTest, TestFaceting, TestSolrConfigHandlerConcurrent, TestBM25SimilarityFactory, IndexSchemaRuntimeFieldTest, TestOrdValues, CdcrUpdateLogTest, TestCollationFieldDocValues, UnloadDistributedZkTest, PreAnalyzedFieldTest, HdfsSyncSliceTest, TestDocBasedVersionConstraints, TestStressLucene, MultiThreadedOCPTest, SolrIndexSplitterTest, BufferStoreTest, DirectUpdateHandlerTest, TestPartialUpdateDeduplication, TestHighlightDedupGrouping, SharedFSAutoReplicaFailoverTest, TestNRTOpen, TestFastLRUCache, SolrCoreCheckLockOnStartupTest, TestFunctionQuery, SuggesterFSTTest, SystemInfoHandlerTest, CollectionReloadTest, ShowFileRequestHandlerTest, OutputWriterTest, TestIndexSearcher, AnalysisAfterCoreReloadTest, OverseerTest, TestMaxScoreQueryParser, DOMUtilTest, DocumentAnalysisRequestHandlerTest, CacheHeaderTest, RecoveryZkTest, TestAnalyzedSuggestions, DeleteReplicaTest, OutOfBoxZkACLAndCredentialsProvidersTest, DistributedSuggestComponentTest, ZkCLITest, TestLazyCores, TestConfigOverlay, TestRecoveryHdfs, TestCloudSchemaless, TestNoOpRegenerator, TestBinaryResponseWriter, DistributedQueryComponentCustomSortTest, SynonymTokenizerTest, SolrCoreTest, TestInitQParser, TestStressReorder, TestJsonFacets, TestShardHandlerFactory, TestSchemaManager, SampleTest, DistanceUnitsTest, TestHashPartitioner, TestExpandComponent, ZkControllerTest, HighlighterMaxOffsetTest, SpatialHeatmapFacetsTest, BasicDistributedZkTest, TestSortingResponseWriter, SuggesterTest, CoreAdminRequestStatusTest, OverriddenZkACLAndCredentialsProvidersTest, UniqFieldsUpdateProcessorFactoryTest, TestReloadAndDeleteDocs, TestDistributedStatsComponentCardinality, HdfsNNFailoverTest, TestManagedSchema, TestStressRecovery, RequiredFieldsTest, JSONWriterTest, TestSolrIndexConfig, SolrPluginUtilsTest, TestLRUCache, DistributedSpellCheckComponentTest, TestManagedSchemaFieldResource, DistanceFunctionTest, RuleEngineTest, DocExpirationUpdateProcessorFactoryTest, TestMacros, TestGroupingSearch, TestHighFrequencyDictionaryFactory, TestLeaderElectionZkExpiry, TestCloudPivotFacet, TestCoreContainer, CdcrReplicationHandlerTest, TestCryptoKeys, QueryElevationComponentTest, SoftAutoCommitTest, TestJmxMonitoredMap, SharedFSAutoReplicaFailoverUtilsTest, TestLFUCache, TestUniqueKeyFieldResource, InfoHandlerTest, PeerSyncTest, MergeStrategyTest, TestComponentsName, TestManagedSynonymFilterFactory, TestQueryUtils, TestCustomSort, RankQueryTest, PathHierarchyTokenizerFactoryTest, ShardRoutingTest, OverseerRolesTest, DefaultValueUpdateProcessorTest, BasicZkTest, TestReplicationHandler, TestRandomDVFaceting, TestJoin, TestStressVersions, TestRangeQuery, SpellCheckComponentTest, BadIndexSchemaTest, TestSort, OverseerCollectionProcessorTest, CurrencyFieldXmlFileTest, SignatureUpdateProcessorFactoryTest, TestExtendedDismaxParser, CoreAdminHandlerTest, SuggesterWFSTTest, SchemaVersionSpecificBehaviorTest, TestUpdate, TestWordDelimiterFilterFactory, DocValuesMultiTest, SolrInfoMBeanTest, LukeRequestHandlerTest, DirectSolrSpellCheckerTest, TestReversedWildcardFilterFactory, PrimitiveFieldTypeTest, FileBasedSpellCheckerTest, RequestHandlersTest, TestIndexingPerformance, FieldAnalysisRequestHandlerTest, TestArbitraryIndexDir, IndexSchemaTest, TestCollationField, ReturnFieldsTest, TestCSVResponseWriter, QueryParsingTest, TestPHPSerializedResponseWriter, PingRequestHandlerTest, SearchHandlerTest, AlternateDirectoryTest, CopyFieldTest, SolrIndexConfigTest, TestDocSet, NumericFieldsTest, TestElisionMultitermQuery, ExternalFileFieldSortTest, TestPostingsSolrHighlighter, SpellPossibilityIteratorTest, TestCharFilters, EchoParamsTest, TestPerFieldSimilarity, TestIBSimilarityFactory, TestFastOutputStream, ScriptEngineTest, PluginInfoTest, PrimUtilsTest, TestSuggestSpellingConverter, DateFieldTest, SpellingQueryConverterTest, ClusterStateTest, TestUtils, TestDocumentBuilder, UUIDFieldTest, FileUtilsTest, CircularListTest, DistributedIntervalFacetingTest, SolrTestCaseJ4Test, TestCursorMarkWithoutUniqueKey, TestDistributedMissingSort, TestSimpleTrackingShardHandler, AsyncMigrateRouteKeyTest, CdcrVersionReplicationTest, CloudExitableDirectoryReaderTest, ConcurrentDeleteAndCreateCollectionTest, ConnectionManagerTest, DeleteInactiveReplicaTest, DeleteShardTest, DistribCursorPagingTest, DistribJoinFromCollectionTest, DistributedQueueTest, DistributedVersionInfoTest, RemoteQueryErrorTest, SimpleCollectionCreateDeleteTest, SolrXmlInZkTest, TestAuthenticationFramework, TestCloudInspectUtil, TestMiniSolrCloudClusterSSL, TestShortCircuitedRequests, HdfsBasicDistributedZkTest, HdfsChaosMonkeySafeLeaderTest, HdfsRecoverLeaseTest, HdfsRecoveryZkTest, HdfsThreadLeakTest, HdfsWriteToMultipleCollectionsTest, StressHdfsTest, TestClusterStateMutator, ZkStateWriterTest, HdfsDirectoryFactoryTest, TestConfigSets, TestDynamicLoading, TestImplicitCoreProperties, TestSolrDynamicMBean, TestSolrXml, RequestLoggingTest, TestConfigReload, DistributedFacetPivotSmallAdvancedTest, DistributedFacetPivotWhiteBoxTest, FacetPivotSmallTest, TestPivotHelperCode, TestTrackingShardHandlerFactory, TestClassNameShortening, TestCopyFieldCollectionResource, TestDynamicFieldCollectionResource, TestDynamicFieldResource, TestFieldCollectionResource, TestFieldResource, TestFieldTypeCollectionResource, TestManagedSchemaDynamicFieldResource, TestCloudManagedSchema, TestCollapseQParserPlugin]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=TestCollapseQParserPlugin -Dtests.seed=B073F48B42910119 -Dtests.slow=true -Dtests.locale=ja -Dtests.timezone=Asia/Thimphu -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
   [junit4] ERROR   0.00s J0 | TestCollapseQParserPlugin (suite) <<<
   [junit4]    > Throwable #1: java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([B073F48B42910119]:0)
   [junit4] Completed [502/502] on J0 in 7232.16s, 1 test, 2 errors <<< FAILURES!

[...truncated 13 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:526: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:474: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:61: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/extra-targets.xml:39: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build.xml:229: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/common-build.xml:512: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1415: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:973: There were test failures: 502 suites, 1981 tests, 1 suite-level error, 1 error, 2 failures, 62 ignored (24 assumptions)

Total time: 190 minutes 21 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any