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/03/18 23:23:04 UTC

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

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

1 tests failed.
FAILED:  org.apache.solr.handler.TestSolrConfigHandlerCloud.test

Error Message:
Could not get expected value  'CY val' for path 'response/params/y/c' full output: {   "responseHeader":{     "status":0,     "QTime":0},   "response":{     "znodeVersion":0,     "params":{"x":{         "a":"A val",         "b":"B val",         "":{"v":0}}}}}

Stack Trace:
java.lang.AssertionError: Could not get expected value  'CY val' for path 'response/params/y/c' full output: {
  "responseHeader":{
    "status":0,
    "QTime":0},
  "response":{
    "znodeVersion":0,
    "params":{"x":{
        "a":"A val",
        "b":"B val",
        "":{"v":0}}}}}
	at __randomizedtesting.SeedInfo.seed([E6844C91EBF03BE1:6ED0734B450C5619]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at org.apache.solr.core.TestSolrConfigHandler.testForResponseElement(TestSolrConfigHandler.java:399)
	at org.apache.solr.handler.TestSolrConfigHandlerCloud.testReqParams(TestSolrConfigHandlerCloud.java:190)
	at org.apache.solr.handler.TestSolrConfigHandlerCloud.test(TestSolrConfigHandlerCloud.java:78)
	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:483)
	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:958)
	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:933)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	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:53)
	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 8943 lines...]
   [junit4] Suite: org.apache.solr.handler.TestSolrConfigHandlerCloud
   [junit4]   2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/init-core-data-001
   [junit4]   2> 34685 T392 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
   [junit4]   2> 34686 T392 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /ai/qo
   [junit4]   2> 34688 T392 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 34688 T393 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 34788 T392 oasc.ZkTestServer.run start zk server on port:46833
   [junit4]   2> 34789 T392 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 34789 T392 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 34791 T400 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f7b808a name:ZooKeeperConnection Watcher:127.0.0.1:46833 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 34792 T392 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 34792 T392 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 34792 T392 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 34793 T392 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 34794 T392 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 34795 T403 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@35395d6 name:ZooKeeperConnection Watcher:127.0.0.1:46833/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 34795 T392 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 34796 T392 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 34796 T392 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 34797 T392 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 34798 T392 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 34798 T392 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 34799 T392 oasc.AbstractZkTestCase.putConfig put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 34800 T392 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 34801 T392 oasc.AbstractZkTestCase.putConfig put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 34801 T392 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 34802 T392 oasc.AbstractZkTestCase.putConfig put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 34802 T392 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 34803 T392 oasc.AbstractZkTestCase.putConfig put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 34803 T392 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 34804 T392 oasc.AbstractZkTestCase.putConfig put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 34804 T392 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 34805 T392 oasc.AbstractZkTestCase.putConfig put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 34805 T392 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 34806 T392 oasc.AbstractZkTestCase.putConfig put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 34806 T392 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 34807 T392 oasc.AbstractZkTestCase.putConfig put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 34807 T392 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 34808 T392 oasc.AbstractZkTestCase.putConfig put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 34808 T392 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 34809 T392 oasc.AbstractZkTestCase.putConfig put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 34809 T392 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 34810 T392 oasc.AbstractZkTestCase.putConfig put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 34810 T392 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 34866 T392 oas.SolrTestCaseJ4.writeCoreProperties Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/control-001/cores/collection1
   [junit4]   2> 34868 T392 oejs.Server.doStart jetty-9.2.9.v20150224
   [junit4]   2> 34870 T392 oejsh.ContextHandler.doStart Started o.e.j.s.ServletContextHandler@b92083d{/ai/qo,null,AVAILABLE}
   [junit4]   2> 34879 T392 oejs.AbstractConnector.doStart Started ServerConnector@487729b8{HTTP/1.1}{127.0.0.1:48331}
   [junit4]   2> 34880 T392 oejs.Server.doStart Started @36018ms
   [junit4]   2> 34880 T392 oascse.JettySolrRunner$1.lifeCycleStarted Jetty properties: {solr.data.dir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/tempDir-001/control/data, hostContext=/ai/qo, hostPort=48331, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/control-001/cores}
   [junit4]   2> 34881 T392 oass.SolrDispatchFilter.init SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@c387f44
   [junit4]   2> 34881 T392 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/control-001/'
   [junit4]   2> 34890 T392 oasc.SolrXmlConfig.fromFile Loading container configuration from /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/control-001/solr.xml
   [junit4]   2> 34894 T392 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/control-001/cores
   [junit4]   2> 34894 T392 oasc.CoreContainer.<init> New CoreContainer 752893702
   [junit4]   2> 34894 T392 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/control-001/]
   [junit4]   2> 34894 T392 oasc.CoreContainer.load loading shared library: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/control-001/lib
   [junit4]   2> 34894 T392 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: lib (resolved as: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/control-001/lib).
   [junit4]   2> 34898 T392 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 34899 T392 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 34899 T392 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 34899 T392 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 34899 T392 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
   [junit4]   2> 34899 T392 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 34899 T392 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 34900 T392 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 34900 T392 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 34900 T392 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 34900 T392 oashc.HttpShardHandlerFactory.getParameter Setting useRetries to: false
   [junit4]   2> 34900 T392 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 34901 T392 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 34901 T392 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 34901 T392 oasc.CoreContainer.load Node Name: 127.0.0.1
   [junit4]   2> 34901 T392 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:46833/solr
   [junit4]   2> 34901 T392 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 34901 T392 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 34902 T392 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 34903 T417 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4b1aec02 name:ZooKeeperConnection Watcher:127.0.0.1:46833 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 34903 T392 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 34904 T392 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 34914 T392 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 34915 T420 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@77193220 name:ZooKeeperConnection Watcher:127.0.0.1:46833/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 34915 T392 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 34916 T392 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 34917 T392 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 34919 T392 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 34920 T392 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 34921 T392 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 34922 T392 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 34923 T392 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 34924 T392 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 34924 T392 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48331_ai%2Fqo
   [junit4]   2> 34925 T392 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48331_ai%2Fqo
   [junit4]   2> 34926 T392 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 34927 T392 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 34928 T392 oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 34929 T392 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:48331_ai%2Fqo
   [junit4]   2> 34929 T392 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 34930 T392 oasc.Overseer.start Overseer (id=93501275885469699-127.0.0.1:48331_ai%2Fqo-n_0000000000) starting
   [junit4]   2> 34931 T392 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 34934 T392 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
   [junit4]   2> 34934 T392 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 34934 T421 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 34934 T422 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 34936 T392 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/control-001/cores
   [junit4]   1> CORE DESCRIPTOR: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, instanceDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/control-001/cores/collection1, collection=control_collection, absoluteInstDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/control-001/cores/collection1/, coreNodeName=, dataDir=data/, shard=}
   [junit4]   2> 34937 T392 oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/control-001/cores/collection1/
   [junit4]   2> 34938 T392 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 34938 T424 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 34938 T424 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 34939 T424 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 34939 T421 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:48331/ai/qo",
   [junit4]   2> 	  "node_name":"127.0.0.1:48331_ai%2Fqo",
   [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> 34939 T421 oasco.ReplicaMutator.updateState Update state numShards=1 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:48331/ai/qo",
   [junit4]   2> 	  "node_name":"127.0.0.1:48331_ai%2Fqo",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 34940 T421 oasco.ClusterStateMutator.createCollection building a new cName: control_collection
   [junit4]   2> 34940 T421 oasco.ReplicaMutator.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 34941 T420 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> 34942 T420 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 35939 T424 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 35939 T424 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 35940 T424 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 35940 T424 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 35940 T424 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 35940 T424 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/control-001/cores/collection1/'
   [junit4]   2> 35949 T424 oasc.ZkController.watchZKConfDir watch zkdir /configs/conf1
   [junit4]   2> 35950 T424 oasc.Config.<init> loaded config solrconfig.xml with version 0 
   [junit4]   2> 35955 T424 oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
   [junit4]   2> 35958 T424 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 35964 T424 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 35964 T424 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 35968 T424 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 36075 T424 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 36080 T424 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 36082 T424 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 36089 T424 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 36091 T424 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 36093 T424 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 36093 T424 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 36093 T424 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 36093 T424 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 36094 T424 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 36094 T424 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 36094 T424 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 36094 T424 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 36095 T424 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/control-001/cores/collection1/, dataDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/control-001/cores/collection1/data/
   [junit4]   2> 36095 T424 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6c844fac
   [junit4]   2> 36096 T424 oasc.CachingDirectoryFactory.get return new directory for /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/control-001/cores/collection1/data
   [junit4]   2> 36096 T424 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/control-001/cores/collection1/data/index/
   [junit4]   2> 36096 T424 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/control-001/cores/collection1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 36097 T424 oasc.CachingDirectoryFactory.get return new directory for /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/control-001/cores/collection1/data/index
   [junit4]   2> 36097 T424 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=14, maxMergeAtOnceExplicit=11, maxMergedSegmentMB=21.369140625, floorSegmentMB=0.4326171875, forceMergeDeletesPctAllowed=28.03005849057903, segmentsPerTier=14.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.11801435765760618
   [junit4]   2> 36098 T424 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@6cc451b1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@743d366e),segFN=segments_1,generation=1}
   [junit4]   2> 36098 T424 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 36103 T424 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 36109 T424 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 36110 T424 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 36110 T424 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 36110 T424 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 36110 T424 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 36111 T424 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 36111 T424 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 36111 T424 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 36113 T424 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 36114 T424 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 36115 T424 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 36116 T424 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 36121 T424 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> 36121 T424 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 36122 T424 oasu.UpdateHandler.<init> Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 36122 T424 oasu.UpdateLog.init Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10
   [junit4]   2> 36123 T424 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 36123 T424 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 36123 T424 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=18, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=89.4541015625, floorSegmentMB=2.158203125, forceMergeDeletesPctAllowed=0.8621139571979097, segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.14519852420359236
   [junit4]   2> 36124 T424 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@6cc451b1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@743d366e),segFN=segments_1,generation=1}
   [junit4]   2> 36124 T424 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 36124 T424 oass.SolrIndexSearcher.<init> Opening Searcher@1b6dd24a[collection1] main
   [junit4]   2> 36125 T424 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 36125 T424 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 36125 T424 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 36126 T424 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 36126 T424 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 36126 T424 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 36126 T424 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 36127 T424 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 36127 T424 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 36127 T424 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 36127 T425 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1b6dd24a[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 36128 T424 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 36128 T428 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:48331/ai/qo collection:control_collection shard:shard1
   [junit4]   2> 36129 T392 oass.SolrDispatchFilter.init user.dir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 36129 T392 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 36129 T428 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 36129 T392 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 36130 T392 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 36131 T431 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@305bf36d name:ZooKeeperConnection Watcher:127.0.0.1:46833/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 36131 T392 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 36131 T392 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 36131 T392 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 36132 T428 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 36133 T420 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 36133 T428 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 36133 T428 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 36133 T392 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> ASYNC  NEW_CORE C79 name=collection1 org.apache.solr.core.SolrCore@5c1f963d url=http://127.0.0.1:48331/ai/qo/collection1 node=127.0.0.1:48331_ai%2Fqo C79_STATE=coll:control_collection core:collection1 props:{core=collection1, base_url=http://127.0.0.1:48331/ai/qo, node_name=127.0.0.1:48331_ai%2Fqo, state=down}
   [junit4]   2> 36133 T428 C79 P48331 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:48331/ai/qo/collection1/
   [junit4]   2> 36133 T421 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> 36133 T428 C79 P48331 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 36133 T392 oasc.AbstractFullDistribZkTestBase.createJettys Creating collection1 with stateFormat=2
   [junit4]   2> 36134 T428 C79 P48331 oasc.SyncStrategy.syncToMe http://127.0.0.1:48331/ai/qo/collection1/ has no replicas
   [junit4]   2> 36134 T392 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 36134 T428 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:48331/ai/qo/collection1/ shard1
   [junit4]   2> 36134 T428 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 36134 T392 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 36135 T434 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2ea982d0 name:ZooKeeperConnection Watcher:127.0.0.1:46833/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 36135 T392 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 36136 T392 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 36136 T420 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 36137 T421 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":"http://127.0.0.1:48331/ai/qo",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "state":"active"} current state version: 1
   [junit4]   2> 36139 T421 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"create",
   [junit4]   2> 	  "name":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "stateFormat":"2"} current state version: 1
   [junit4]   2> 36139 T421 oasco.ClusterStateMutator.createCollection building a new cName: collection1
   [junit4]   2> 36139 T420 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> 36140 T431 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> 36143 T420 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 36184 T392 oas.SolrTestCaseJ4.writeCoreProperties Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-1-001/cores/collection1
   [junit4]   2> 36184 T392 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1 in directory /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-1-001
   [junit4]   2> 36185 T392 oejs.Server.doStart jetty-9.2.9.v20150224
   [junit4]   2> 36186 T392 oejsh.ContextHandler.doStart Started o.e.j.s.ServletContextHandler@51a5b796{/ai/qo,null,AVAILABLE}
   [junit4]   2> 36187 T392 oejs.AbstractConnector.doStart Started ServerConnector@417aabb7{HTTP/1.1}{127.0.0.1:49180}
   [junit4]   2> 36187 T392 oejs.Server.doStart Started @37325ms
   [junit4]   2> 36187 T428 oasc.ZkController.register We are http://127.0.0.1:48331/ai/qo/collection1/ and leader is http://127.0.0.1:48331/ai/qo/collection1/
   [junit4]   2> 36187 T392 oascse.JettySolrRunner$1.lifeCycleStarted Jetty properties: {solr.data.dir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/tempDir-001/jetty1, solrconfig=solrconfig.xml, hostContext=/ai/qo, hostPort=49180, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-1-001/cores}
   [junit4]   2> 36187 T428 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:48331/ai/qo
   [junit4]   2> 36187 T428 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 36188 T428 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 36188 T428 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 36188 T392 oass.SolrDispatchFilter.init SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@c387f44
   [junit4]   2> 36188 T392 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-1-001/'
   [junit4]   2> 36189 T420 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 36193 T421 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:48331/ai/qo",
   [junit4]   2> 	  "node_name":"127.0.0.1:48331_ai%2Fqo",
   [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> 36193 T421 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:48331/ai/qo",
   [junit4]   2> 	  "node_name":"127.0.0.1:48331_ai%2Fqo",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 36194 T421 oasco.ZkStateWriter.writePendingUpdates going to create_collection /collections/collection1/state.json
   [junit4]   2> 36194 T420 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> 36194 T431 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> 36197 T392 oasc.SolrXmlConfig.fromFile Loading container configuration from /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-1-001/solr.xml
   [junit4]   2> 36200 T392 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-1-001/cores
   [junit4]   2> 36200 T392 oasc.CoreContainer.<init> New CoreContainer 5072939
   [junit4]   2> 36200 T392 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-1-001/]
   [junit4]   2> 36201 T392 oasc.CoreContainer.load loading shared library: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-1-001/lib
   [junit4]   2> 36201 T392 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: lib (resolved as: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-1-001/lib).
   [junit4]   2> 36205 T392 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 36205 T392 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 36205 T392 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 36205 T392 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 36205 T392 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
   [junit4]   2> 36205 T392 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 36205 T392 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 36206 T392 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 36206 T392 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 36206 T392 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 36206 T392 oashc.HttpShardHandlerFactory.getParameter Setting useRetries to: false
   [junit4]   2> 36206 T392 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 36206 T392 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 36207 T392 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 36207 T392 oasc.CoreContainer.load Node Name: 127.0.0.1
   [junit4]   2> 36207 T392 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:46833/solr
   [junit4]   2> 36207 T392 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 36207 T392 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 36208 T392 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 36209 T448 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5a889fae name:ZooKeeperConnection Watcher:127.0.0.1:46833 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 36209 T392 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 36210 T392 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 36211 T392 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 36212 T451 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@75c4694c name:ZooKeeperConnection Watcher:127.0.0.1:46833/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 36212 T392 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 36215 T392 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 36297 T451 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> 36297 T431 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> 36297 T420 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> 37217 T392 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49180_ai%2Fqo
   [junit4]   2> 37217 T392 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49180_ai%2Fqo
   [junit4]   2> 37219 T392 oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 37219 T392 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-1-001/cores
   [junit4]   1> CORE DESCRIPTOR: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, instanceDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-1-001/cores/collection1, collection=collection1, absoluteInstDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-1-001/cores/collection1/, coreNodeName=, dataDir=data/, shard=}
   [junit4]   2> 37220 T392 oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-1-001/cores/collection1/
   [junit4]   2> 37221 T392 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 37222 T452 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 37222 T452 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 37222 T420 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 37223 T452 oasc.ZkController.preRegister Registering watch for external collection collection1
   [junit4]   2> 37223 T452 oascc.ZkStateReader.addZkWatch addZkWatch collection1
   [junit4]   2> 37223 T421 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:49180/ai/qo",
   [junit4]   2> 	  "node_name":"127.0.0.1:49180_ai%2Fqo",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"} current state version: 4
   [junit4]   2> 37223 T452 oascc.ZkStateReader.addZkWatch Updating collection state at /collections/collection1/state.json from ZooKeeper... 
   [junit4]   2> 37223 T421 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:49180/ai/qo",
   [junit4]   2> 	  "node_name":"127.0.0.1:49180_ai%2Fqo",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 37223 T421 oasco.ReplicaMutator.updateState Collection already exists with numShards=2
   [junit4]   2> 37224 T421 oasco.ReplicaMutator.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 37224 T452 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 0 
   [junit4]   2> 37224 T452 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 37325 T421 oasco.ZkStateWriter.writePendingUpdates going to update_collection /collections/collection1/state.json version: 0
   [junit4]   2> 37325 T451 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json for collection collection1 has occurred - updating... (live nodes size: 2)
   [junit4]   2> 37326 T451 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 1 
   [junit4]   2> 38224 T452 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 38224 T452 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 38225 T452 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 38225 T452 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 38225 T452 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 38225 T452 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-1-001/cores/collection1/'
   [junit4]   2> 38230 T452 oasc.ZkController.watchZKConfDir watch zkdir /configs/conf1
   [junit4]   2> 38231 T452 oasc.Config.<init> loaded config solrconfig.xml with version 0 
   [junit4]   2> 38234 T452 oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
   [junit4]   2> 38242 T452 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 38246 T452 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 38247 T452 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 38250 T452 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 38298 T452 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 38302 T452 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 38302 T452 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 38307 T452 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 38308 T452 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 38309 T452 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 38310 T452 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 38310 T452 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 38310 T452 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 38310 T452 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 38311 T452 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 38311 T452 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 38311 T452 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 38311 T452 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-1-001/cores/collection1/, dataDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-1-001/cores/collection1/data/
   [junit4]   2> 38311 T452 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6c844fac
   [junit4]   2> 38312 T452 oasc.CachingDirectoryFactory.get return new directory for /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-1-001/cores/collection1/data
   [junit4]   2> 38312 T452 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-1-001/cores/collection1/data/index/
   [junit4]   2> 38312 T452 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-1-001/cores/collection1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 38312 T452 oasc.CachingDirectoryFactory.get return new directory for /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-1-001/cores/collection1/data/index
   [junit4]   2> 38312 T452 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=14, maxMergeAtOnceExplicit=11, maxMergedSegmentMB=21.369140625, floorSegmentMB=0.4326171875, forceMergeDeletesPctAllowed=28.03005849057903, segmentsPerTier=14.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.11801435765760618
   [junit4]   2> 38313 T452 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@190e06f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@54cfce7d),segFN=segments_1,generation=1}
   [junit4]   2> 38313 T452 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 38319 T452 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 38319 T452 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 38319 T452 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 38319 T452 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 38320 T452 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 38320 T452 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 38320 T452 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 38321 T452 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 38322 T452 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 38323 T452 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 38325 T452 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 38326 T452 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 38327 T452 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 38334 T452 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> 38335 T452 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 38335 T452 oasu.UpdateHandler.<init> Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 38336 T452 oasu.UpdateLog.init Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10
   [junit4]   2> 38336 T452 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 38336 T452 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 38337 T452 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=18, maxMergeAtOnceExplicit=41, maxMergedSegmentMB=89.4541015625, floorSegmentMB=2.158203125, forceMergeDeletesPctAllowed=0.8621139571979097, segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.14519852420359236
   [junit4]   2> 38338 T452 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@190e06f3 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@54cfce7d),segFN=segments_1,generation=1}
   [junit4]   2> 38338 T452 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 38338 T452 oass.SolrIndexSearcher.<init> Opening Searcher@27927d41[collection1] main
   [junit4]   2> 38338 T452 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 38339 T452 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 38339 T452 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 38339 T452 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 38340 T452 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 38340 T452 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 38340 T452 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 38340 T452 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 38340 T452 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 38341 T452 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 38341 T453 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@27927d41[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 38342 T452 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 38342 T456 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49180/ai/qo collection:collection1 shard:shard2
   [junit4]   2> 38342 T392 oass.SolrDispatchFilter.init user.dir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 38343 T392 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 38343 T456 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 38346 T456 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 38347 T420 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 38347 T456 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 38347 T456 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C80 name=collection1 org.apache.solr.core.SolrCore@6f4f9a68 url=http://127.0.0.1:49180/ai/qo/collection1 node=127.0.0.1:49180_ai%2Fqo C80_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=http://127.0.0.1:49180/ai/qo, node_name=127.0.0.1:49180_ai%2Fqo, state=down}
   [junit4]   2> 38347 T456 C80 P49180 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49180/ai/qo/collection1/
   [junit4]   2> 38347 T421 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> 38348 T456 C80 P49180 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 38348 T456 C80 P49180 oasc.SyncStrategy.syncToMe http://127.0.0.1:49180/ai/qo/collection1/ has no replicas
   [junit4]   2> 38348 T456 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49180/ai/qo/collection1/ shard2
   [junit4]   2> 38348 T456 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 38348 T421 oasco.ZkStateWriter.writePendingUpdates going to update_collection /collections/collection1/state.json version: 1
   [junit4]   2> 38349 T451 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json for collection collection1 has occurred - updating... (live nodes size: 2)
   [junit4]   2> 38349 T451 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 2 
   [junit4]   2> 38351 T420 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 38351 T421 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:49180/ai/qo",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "state":"active"} current state version: 4
   [junit4]   2> 38352 T421 oasco.ZkStateWriter.writePendingUpdates going to update_collection /collections/collection1/state.json version: 2
   [junit4]   2> 38352 T451 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json for collection collection1 has occurred - updating... (live nodes size: 2)
   [junit4]   2> 38352 T451 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 3 
   [junit4]   2> 38391 T392 oas.SolrTestCaseJ4.writeCoreProperties Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-2-001/cores/collection1
   [junit4]   2> 38392 T392 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2 in directory /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-2-001
   [junit4]   2> 38392 T392 oejs.Server.doStart jetty-9.2.9.v20150224
   [junit4]   2> 38394 T392 oejsh.ContextHandler.doStart Started o.e.j.s.ServletContextHandler@784bc5bc{/ai/qo,null,AVAILABLE}
   [junit4]   2> 38394 T392 oejs.AbstractConnector.doStart Started ServerConnector@715f8756{HTTP/1.1}{127.0.0.1:36694}
   [junit4]   2> 38395 T392 oejs.Server.doStart Started @39533ms
   [junit4]   2> 38395 T392 oascse.JettySolrRunner$1.lifeCycleStarted Jetty properties: {solr.data.dir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/tempDir-001/jetty2, solrconfig=solrconfig.xml, hostContext=/ai/qo, hostPort=36694, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-2-001/cores}
   [junit4]   2> 38395 T392 oass.SolrDispatchFilter.init SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@c387f44
   [junit4]   2> 38395 T392 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-2-001/'
   [junit4]   2> 38401 T456 oasc.ZkController.register We are http://127.0.0.1:49180/ai/qo/collection1/ and leader is http://127.0.0.1:49180/ai/qo/collection1/
   [junit4]   2> 38401 T456 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49180/ai/qo
   [junit4]   2> 38401 T456 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 38401 T456 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 38402 T456 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 38402 T392 oasc.SolrXmlConfig.fromFile Loading container configuration from /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-2-001/solr.xml
   [junit4]   2> 38403 T420 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 38403 T421 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:49180/ai/qo",
   [junit4]   2> 	  "node_name":"127.0.0.1:49180_ai%2Fqo",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"} current state version: 4
   [junit4]   2> 38403 T421 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:49180/ai/qo",
   [junit4]   2> 	  "node_name":"127.0.0.1:49180_ai%2Fqo",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 38404 T421 oasco.ZkStateWriter.writePendingUpdates going to update_collection /collections/collection1/state.json version: 3
   [junit4]   2> 38404 T456 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 3 
   [junit4]   2> 38405 T451 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json for collection collection1 has occurred - updating... (live nodes size: 2)
   [junit4]   2> 38405 T451 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 4 
   [junit4]   2> 38405 T392 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-2-001/cores
   [junit4]   2> 38406 T392 oasc.CoreContainer.<init> New CoreContainer 1573658744
   [junit4]   2> 38406 T392 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-2-001/]
   [junit4]   2> 38406 T392 oasc.CoreContainer.load loading shared library: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-2-001/lib
   [junit4]   2> 38406 T392 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: lib (resolved as: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-2-001/lib).
   [junit4]   2> 38410 T392 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 38410 T392 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 38410 T392 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 38410 T392 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 38410 T392 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
   [junit4]   2> 38411 T392 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 38411 T392 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 38411 T392 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 38411 T392 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 38411 T392 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 38411 T392 oashc.HttpShardHandlerFactory.getParameter Setting useRetries to: false
   [junit4]   2> 38412 T392 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 38412 T392 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 38412 T392 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 38412 T392 oasc.CoreContainer.load Node Name: 127.0.0.1
   [junit4]   2> 38413 T392 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:46833/solr
   [junit4]   2> 38413 T392 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 38413 T392 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 38413 T392 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 38415 T470 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3dcd402a name:ZooKeeperConnection Watcher:127.0.0.1:46833 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 38415 T392 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 38416 T392 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 38417 T392 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 38419 T473 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@43a17a02 name:ZooKeeperConnection Watcher:127.0.0.1:46833/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 38419 T392 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 38421 T392 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 39423 T392 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36694_ai%2Fqo
   [junit4]   2> 39424 T392 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36694_ai%2Fqo
   [junit4]   2> 39425 T392 oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 39427 T392 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-2-001/cores
   [junit4]   1> CORE DESCRIPTOR: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, instanceDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-2-001/cores/collection1, collection=collection1, absoluteInstDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-2-001/cores/collection1/, coreNodeName=, dataDir=data/, shard=}
   [junit4]   2> 39428 T392 oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-2-001/cores/collection1/
   [junit4]   2> 39428 T392 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 39429 T474 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 39430 T474 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 39430 T420 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 39431 T474 oasc.ZkController.preRegister Registering watch for external collection collection1
   [junit4]   2> 39431 T474 oascc.ZkStateReader.addZkWatch addZkWatch collection1
   [junit4]   2> 39431 T421 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:36694/ai/qo",
   [junit4]   2> 	  "node_name":"127.0.0.1:36694_ai%2Fqo",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"} current state version: 4
   [junit4]   2> 39431 T474 oascc.ZkStateReader.addZkWatch Updating collection state at /collections/collection1/state.json from ZooKeeper... 
   [junit4]   2> 39431 T421 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:36694/ai/qo",
   [junit4]   2> 	  "node_name":"127.0.0.1:36694_ai%2Fqo",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 39431 T421 oasco.ReplicaMutator.updateState Collection already exists with numShards=2
   [junit4]   2> 39431 T421 oasco.ReplicaMutator.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 39432 T474 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 4 
   [junit4]   2> 39432 T474 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 39432 T421 oasco.ZkStateWriter.writePendingUpdates going to update_collection /collections/collection1/state.json version: 4
   [junit4]   2> 39432 T451 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json for collection collection1 has occurred - updating... (live nodes size: 3)
   [junit4]   2> 39433 T473 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json for collection collection1 has occurred - updating... (live nodes size: 3)
   [junit4]   2> 39433 T451 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 5 
   [junit4]   2> 39433 T473 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 5 
   [junit4]   2> 40432 T474 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 40432 T474 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 40433 T474 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 40433 T474 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 40433 T474 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 40433 T474 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-2-001/cores/collection1/'
   [junit4]   2> 40439 T474 oasc.ZkController.watchZKConfDir watch zkdir /configs/conf1
   [junit4]   2> 40440 T474 oasc.Config.<init> loaded config solrconfig.xml with version 0 
   [junit4]   2> 40443 T474 oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
   [junit4]   2> 40446 T474 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 40453 T474 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 40454 T474 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 40457 T474 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 40507 T474 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 40511 T474 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 40512 T474 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 40517 T474 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 40519 T474 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 40521 T474 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 40521 T474 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 40521 T474 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 40521 T474 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 40522 T474 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 40522 T474 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 40522 T474 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 40522 T474 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 40523 T474 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-2-001/cores/collection1/, dataDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-2-001/cores/collection1/data/
   [junit4]   2> 40523 T474 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6c844fac
   [junit4]   2> 40524 T474 oasc.CachingDirectoryFactory.get return new directory for /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-2-001/cores/collection1/data
   [junit4]   2> 40524 T474 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-2-001/cores/collection1/data/index/
   [junit4]   2> 40524 T474 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-2-001/cores/collection1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 40524 T474 oasc.CachingDirectoryFactory.get return new directory for /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-2-001/cores/collection1/data/index
   [junit4]   2> 40525 T474 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=14, maxMergeAtOnceExplicit=11, maxMergedSegmentMB=21.369140625, floorSegmentMB=0.4326171875, forceMergeDeletesPctAllowed=28.03005849057903, segmentsPerTier=14.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.11801435765760618
   [junit4]   2> 40525 T474 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@57d10c90 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3c075117),segFN=segments_1,generation=1}
   [junit4]   2> 40526 T474 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 40532 T474 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 40532 T474 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 40532 T474 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 40532 T474 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 40533 T474 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 40533 T474 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 40533 T474 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 40533 T474 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 40533 T474 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 40535 T474 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 40537 T474 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 40538 T474 oashl.XMLLoader

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

tcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 69082 T392 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@2c92e89a
   [junit4]   2> 69083 T392 oasc.ZkController.unRegisterConfListener  a listener was removed because of core close
   [junit4]   2> 69083 T392 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=0}
   [junit4]   2> 69083 T741 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node4",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:45574/ai/qo",
   [junit4]   2> 	  "node_name":"127.0.0.1:45574_ai%2Fqo",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"} current state version: 5
   [junit4]   2> 69083 T392 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 69083 T392 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 69083 T392 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 69083 T741 oasco.ReplicaMutator.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node4",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:45574/ai/qo",
   [junit4]   2> 	  "node_name":"127.0.0.1:45574_ai%2Fqo",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 69084 T392 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 69085 T741 oasco.ZkStateWriter.writePendingUpdates going to update_collection /collections/collection1/state.json version: 21
   [junit4]   2> 69085 T740 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json for collection collection1 has occurred - updating... (live nodes size: 1)
   [junit4]   2> 69086 T740 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 22 
   [junit4]   2> 69086 T392 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 69086 T392 oasc.CachingDirectoryFactory.closeCacheValue looking to close /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-4-001/cores/collection1/data [CachedDir<<refCount=0;path=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-4-001/cores/collection1/data;done=false>>]
   [junit4]   2> 69087 T392 oasc.CachingDirectoryFactory.close Closing directory: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-4-001/cores/collection1/data
   [junit4]   2> 69087 T392 oasc.CachingDirectoryFactory.closeCacheValue looking to close /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-4-001/cores/collection1/data/index [CachedDir<<refCount=0;path=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-4-001/cores/collection1/data/index;done=false>>]
   [junit4]   2> 69087 T392 oasc.CachingDirectoryFactory.close Closing directory: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001/shard-4-001/cores/collection1/data/index
   [junit4]   2> 69087 T392 oasc.Overseer.close Overseer (id=93501275885469709-127.0.0.1:45574_ai%2Fqo-n_0000000004) closing
   [junit4]   2> 69087 T741 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:45574_ai%2Fqo
   [junit4]   2> 70588 T740 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 70590 T392 oejs.AbstractConnector.doStop Stopped ServerConnector@3bb7d029{HTTP/1.1}{127.0.0.1:0}
   [junit4]   2> 70590 T392 oejsh.ContextHandler.doStop Stopped o.e.j.s.ServletContextHandler@5a5a05e9{/ai/qo,null,UNAVAILABLE}
   [junit4]   2> 70591 T392 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:46833 46833
   [junit4]   2> 70618 T393 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:46833 46833
   [junit4]   2> 70619 T393 oasc.ZkTestServer$ZKServerMain.runFromConfig WARN Watch limit violations: 
   [junit4]   2> 	Maximum concurrent create/delete watches above limit:
   [junit4]   2> 	
   [junit4]   2> 		100	/solr/configs/conf1
   [junit4]   2> 		6	/solr/aliases.json
   [junit4]   2> 		6	/solr/clusterstate.json
   [junit4]   2> 		4	/solr/collections/collection1/state.json
   [junit4]   2> 	
   [junit4]   2> 	Maximum concurrent children watches above limit:
   [junit4]   2> 	
   [junit4]   2> 		6	/solr/live_nodes
   [junit4]   2> 		5	/solr/overseer/queue
   [junit4]   2> 		5	/solr/overseer/collection-queue-work
   [junit4]   2> 	
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=TestSolrConfigHandlerCloud -Dtests.method=test -Dtests.seed=E6844C91EBF03BE1 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ar_BH -Dtests.timezone=America/Tijuana -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
   [junit4] FAILURE 35.9s J1 | TestSolrConfigHandlerCloud.test <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: Could not get expected value  'CY val' for path 'response/params/y/c' full output: {
   [junit4]    >   "responseHeader":{
   [junit4]    >     "status":0,
   [junit4]    >     "QTime":0},
   [junit4]    >   "response":{
   [junit4]    >     "znodeVersion":0,
   [junit4]    >     "params":{"x":{
   [junit4]    >         "a":"A val",
   [junit4]    >         "b":"B val",
   [junit4]    >         "":{"v":0}}}}}
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([E6844C91EBF03BE1:6ED0734B450C5619]:0)
   [junit4]    > 	at org.apache.solr.core.TestSolrConfigHandler.testForResponseElement(TestSolrConfigHandler.java:399)
   [junit4]    > 	at org.apache.solr.handler.TestSolrConfigHandlerCloud.testReqParams(TestSolrConfigHandlerCloud.java:190)
   [junit4]    > 	at org.apache.solr.handler.TestSolrConfigHandlerCloud.test(TestSolrConfigHandlerCloud.java:78)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:958)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:933)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 70625 T392 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.handler.TestSolrConfigHandlerCloud E6844C91EBF03BE1-001
   [junit4]   2> 35941 T391 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
   [junit4]   2> NOTE: test params are: codec=CheapBastard, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=ar_BH, timezone=America/Tijuana
   [junit4]   2> NOTE: Linux 3.13.0-46-generic amd64/Oracle Corporation 1.8.0_31 (64-bit)/cpus=12,threads=1,free=297320088,total=508887040
   [junit4]   2> NOTE: All tests run in this JVM: [IndexSchemaRuntimeFieldTest, TestNRTOpen, TestRTGBase, SystemInfoHandlerTest, TestFoldingMultitermQuery, ZkControllerTest, TestManagedResource, SuggesterTSTTest, RAMDirectoryFactoryTest, TestBulkSchemaConcurrent, SolrPluginUtilsTest, TestRecoveryHdfs, TestSolrConfigHandlerCloud]
   [junit4] Completed on J1 in 36.46s, 1 test, 1 failure <<< FAILURES!

[...truncated 1386 lines...]
BUILD FAILED
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:519: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:467: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:61: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:39: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:191: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:510: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1351: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:958: There were test failures: 475 suites, 1891 tests, 1 failure, 48 ignored (21 assumptions)

Total time: 40 minutes 45 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 64bit/jdk1.8.0_31 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any



[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.9.0-ea-b47) - Build # 12005 - Still Failing!

Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/12005/
Java: 32bit/jdk1.9.0-ea-b47 -server -XX:+UseParallelGC

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

Error Message:
Error from server at http://127.0.0.1:34587/compositeid_collection_with_routerfield_shard1_replica1: no servers hosting shard: 

Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:34587/compositeid_collection_with_routerfield_shard1_replica1: no servers hosting shard: 
	at __randomizedtesting.SeedInfo.seed([93D2F7D5C020BCB5:1B86C80F6EDCD14D]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:584)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:236)
	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:228)
	at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:135)
	at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:943)
	at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:958)
	at org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.testDeleteByIdCompositeRouterWithRouterField(FullSolrCloudDistribCmdsTest.java:357)
	at org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.test(FullSolrCloudDistribCmdsTest.java:146)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:498)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java: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:958)
	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:933)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	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:53)
	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 9155 lines...]
   [junit4] Suite: org.apache.solr.cloud.FullSolrCloudDistribCmdsTest
   [junit4]   2> Creating dataDir: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/init-core-data-001
   [junit4]   2> 132922 T1402 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 132924 T1402 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 132926 T1403 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 133026 T1402 oasc.ZkTestServer.run start zk server on port:46227
   [junit4]   2> 133027 T1402 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 133029 T1402 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 133040 T1410 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16a73ed name:ZooKeeperConnection Watcher:127.0.0.1:46227 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 133040 T1402 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 133041 T1402 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 133041 T1402 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 133044 T1404 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x14c2f51d9c40000, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 133046 T1402 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 133047 T1402 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 133047 T1413 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11a45e0 name:ZooKeeperConnection Watcher:127.0.0.1:46227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 133049 T1402 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 133049 T1402 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 133050 T1402 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 133055 T1402 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 133057 T1402 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 133059 T1402 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 133068 T1402 oasc.AbstractZkTestCase.putConfig put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 133069 T1402 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 133071 T1402 oasc.AbstractZkTestCase.putConfig put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
   [junit4]   2> 133071 T1402 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 133072 T1402 oasc.AbstractZkTestCase.putConfig put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 133072 T1402 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 133074 T1402 oasc.AbstractZkTestCase.putConfig put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 133074 T1402 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 133075 T1402 oasc.AbstractZkTestCase.putConfig put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 133075 T1402 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 133076 T1402 oasc.AbstractZkTestCase.putConfig put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 133076 T1402 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 133077 T1402 oasc.AbstractZkTestCase.putConfig put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 133078 T1402 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 133078 T1402 oasc.AbstractZkTestCase.putConfig put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 133079 T1402 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 133079 T1402 oasc.AbstractZkTestCase.putConfig put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 133080 T1402 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 133081 T1402 oasc.AbstractZkTestCase.putConfig put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 133082 T1402 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 133083 T1402 oasc.AbstractZkTestCase.putConfig put /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 133084 T1402 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 133086 T1404 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x14c2f51d9c40001, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 133162 T1402 oas.SolrTestCaseJ4.writeCoreProperties Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/control-001/cores/collection1
   [junit4]   2> 133163 T1402 oejs.Server.doStart jetty-9.2.9.v20150224
   [junit4]   2> 133164 T1402 oejsh.ContextHandler.doStart Started o.e.j.s.ServletContextHandler@141a978{/,null,AVAILABLE}
   [junit4]   2> 133167 T1402 oejs.AbstractConnector.doStart Started ServerConnector@35e912{HTTP/1.1}{127.0.0.1:46366}
   [junit4]   2> 133167 T1402 oejs.Server.doStart Started @133958ms
   [junit4]   2> 133168 T1402 oascse.JettySolrRunner$1.lifeCycleStarted Jetty properties: {solr.data.dir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/tempDir-001/control/data, hostContext=/, hostPort=46366, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/control-001/cores}
   [junit4]   2> 133168 T1402 oass.SolrDispatchFilter.init SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@6f3b58
   [junit4]   2> 133169 T1402 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/control-001/'
   [junit4]   2> 133180 T1402 oasc.SolrXmlConfig.fromFile Loading container configuration from /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/control-001/solr.xml
   [junit4]   2> 133183 T1402 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/control-001/cores
   [junit4]   2> 133184 T1402 oasc.CoreContainer.<init> New CoreContainer 30477415
   [junit4]   2> 133184 T1402 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/control-001/]
   [junit4]   2> 133184 T1402 oasc.CoreContainer.load loading shared library: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/control-001/lib
   [junit4]   2> 133184 T1402 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: lib (resolved as: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/control-001/lib).
   [junit4]   2> 133189 T1402 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 133190 T1402 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 133190 T1402 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 133190 T1402 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 133190 T1402 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
   [junit4]   2> 133190 T1402 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 133190 T1402 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 133191 T1402 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 133191 T1402 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 133191 T1402 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 133191 T1402 oashc.HttpShardHandlerFactory.getParameter Setting useRetries to: false
   [junit4]   2> 133191 T1402 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 133192 T1402 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 133192 T1402 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 133192 T1402 oasc.CoreContainer.load Node Name: 127.0.0.1
   [junit4]   2> 133192 T1402 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:46227/solr
   [junit4]   2> 133192 T1402 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 133192 T1402 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 133193 T1402 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 133198 T1427 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ad30aa name:ZooKeeperConnection Watcher:127.0.0.1:46227 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 133199 T1402 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 133200 T1402 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 133202 T1402 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 133202 T1430 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f5c2ff name:ZooKeeperConnection Watcher:127.0.0.1:46227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 133202 T1402 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 133203 T1402 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 133204 T1402 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 133205 T1402 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 133206 T1402 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 133208 T1402 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 133209 T1402 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 133210 T1402 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 133210 T1402 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 133211 T1402 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46366_
   [junit4]   2> 133212 T1402 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:46366_
   [junit4]   2> 133212 T1402 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 133214 T1402 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 133214 T1402 oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 133215 T1402 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:46366_
   [junit4]   2> 133215 T1402 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 133216 T1402 oasc.Overseer.start Overseer (id=93501720860295171-127.0.0.1:46366_-n_0000000000) starting
   [junit4]   2> 133217 T1402 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 133219 T1402 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
   [junit4]   2> 133219 T1432 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 133219 T1402 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 133220 T1431 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 133221 T1402 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/control-001/cores
   [junit4]   1> CORE DESCRIPTOR: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, instanceDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/control-001/cores/collection1, collection=control_collection, absoluteInstDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/control-001/cores/collection1/, coreNodeName=, dataDir=data/, shard=}
   [junit4]   2> 133222 T1402 oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/control-001/cores/collection1/
   [junit4]   2> 133222 T1402 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 133224 T1434 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 133224 T1434 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 133224 T1434 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 133225 T1431 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:46366",
   [junit4]   2> 	  "node_name":"127.0.0.1:46366_",
   [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> 133225 T1431 oasco.ReplicaMutator.updateState Update state numShards=1 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:46366",
   [junit4]   2> 	  "node_name":"127.0.0.1:46366_",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 133225 T1431 oasco.ClusterStateMutator.createCollection building a new cName: control_collection
   [junit4]   2> 133226 T1431 oasco.ReplicaMutator.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 133226 T1430 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> 133227 T1430 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 134224 T1434 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 134225 T1434 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 134225 T1434 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 134226 T1434 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 134226 T1434 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 134226 T1434 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/control-001/cores/collection1/'
   [junit4]   2> 134237 T1434 oasc.ZkController.watchZKConfDir watch zkdir /configs/conf1
   [junit4]   2> 134238 T1434 oasc.Config.<init> loaded config solrconfig.xml with version 0 
   [junit4]   2> 134241 T1434 oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
   [junit4]   2> 134243 T1434 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 134248 T1434 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 134249 T1434 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 134252 T1434 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 134325 T1434 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 134326 T1434 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 134327 T1434 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 134330 T1434 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 134344 T1434 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 134344 T1434 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 134345 T1434 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/control-001/cores/collection1/, dataDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/control-001/cores/collection1/data/
   [junit4]   2> 134345 T1434 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d1bc4
   [junit4]   2> 134345 T1434 oasc.CachingDirectoryFactory.get return new directory for /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/control-001/cores/collection1/data
   [junit4]   2> 134345 T1434 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/control-001/cores/collection1/data/index/
   [junit4]   2> 134345 T1434 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/control-001/cores/collection1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 134346 T1434 oasc.CachingDirectoryFactory.get return new directory for /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/control-001/cores/collection1/data/index
   [junit4]   2> 134346 T1434 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=11, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1199888713279055]
   [junit4]   2> 134346 T1434 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1e9f4f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@c87c1c),segFN=segments_1,generation=1}
   [junit4]   2> 134347 T1434 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 134349 T1434 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 134349 T1434 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 134349 T1434 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 134349 T1434 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 134350 T1434 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 134350 T1434 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 134350 T1434 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 134350 T1434 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 134350 T1434 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 134352 T1434 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 134355 T1434 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 134356 T1434 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 134357 T1434 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 134360 T1434 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> 134361 T1434 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 134362 T1434 oasu.UpdateHandler.<init> Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 134362 T1434 oasu.UpdateLog.init Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10
   [junit4]   2> 134362 T1434 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 134363 T1434 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 134363 T1434 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=49, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 134363 T1434 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1e9f4f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@c87c1c),segFN=segments_1,generation=1}
   [junit4]   2> 134364 T1434 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 134364 T1434 oass.SolrIndexSearcher.<init> Opening Searcher@1220fd[collection1] main
   [junit4]   2> 134364 T1434 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 134364 T1434 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 134365 T1434 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 134365 T1434 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 134366 T1434 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 134366 T1434 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 134366 T1434 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 134366 T1434 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 134366 T1434 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 134366 T1434 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 134367 T1435 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1220fd[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 134367 T1434 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 134368 T1438 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:46366 collection:control_collection shard:shard1
   [junit4]   2> 134368 T1402 oass.SolrDispatchFilter.init user.dir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2
   [junit4]   2> 134368 T1402 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 134370 T1402 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 134370 T1402 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 134370 T1438 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 134371 T1441 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@493621 name:ZooKeeperConnection Watcher:127.0.0.1:46227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 134371 T1402 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 134371 T1402 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 134372 T1402 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 134375 T1438 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 134376 T1402 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 134387 T1430 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 134387 T1438 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 134387 T1438 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 134387 T1431 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> ASYNC  NEW_CORE C119 name=collection1 org.apache.solr.core.SolrCore@1a993de url=http://127.0.0.1:46366/collection1 node=127.0.0.1:46366_ C119_STATE=coll:control_collection core:collection1 props:{core=collection1, base_url=http://127.0.0.1:46366, node_name=127.0.0.1:46366_, state=down}
   [junit4]   2> 134387 T1438 C119 P46366 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:46366/collection1/
   [junit4]   2> 134388 T1438 C119 P46366 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 134388 T1438 C119 P46366 oasc.SyncStrategy.syncToMe http://127.0.0.1:46366/collection1/ has no replicas
   [junit4]   2> 134388 T1438 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:46366/collection1/ shard1
   [junit4]   2> 134388 T1438 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 134392 T1430 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 134393 T1431 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":"http://127.0.0.1:46366",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "state":"active"} current state version: 1
   [junit4]   2> 134447 T1402 oas.SolrTestCaseJ4.writeCoreProperties Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-1-001/cores/collection1
   [junit4]   2> 134448 T1402 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1 in directory /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-1-001
   [junit4]   2> 134448 T1402 oejs.Server.doStart jetty-9.2.9.v20150224
   [junit4]   2> 134469 T1402 oejsh.ContextHandler.doStart Started o.e.j.s.ServletContextHandler@1ff95e5{/,null,AVAILABLE}
   [junit4]   2> 134470 T1402 oejs.AbstractConnector.doStart Started ServerConnector@a4cf9f{HTTP/1.1}{127.0.0.1:34587}
   [junit4]   2> 134470 T1402 oejs.Server.doStart Started @135261ms
   [junit4]   2> 134471 T1402 oascse.JettySolrRunner$1.lifeCycleStarted Jetty properties: {solr.data.dir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/tempDir-001/jetty1, solrconfig=solrconfig.xml, hostContext=/, hostPort=34587, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-1-001/cores}
   [junit4]   2> 134471 T1402 oass.SolrDispatchFilter.init SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@6f3b58
   [junit4]   2> 134471 T1402 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-1-001/'
   [junit4]   2> 134485 T1402 oasc.SolrXmlConfig.fromFile Loading container configuration from /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-1-001/solr.xml
   [junit4]   2> 134491 T1402 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-1-001/cores
   [junit4]   2> 134491 T1402 oasc.CoreContainer.<init> New CoreContainer 13354782
   [junit4]   2> 134492 T1402 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-1-001/]
   [junit4]   2> 134492 T1402 oasc.CoreContainer.load loading shared library: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-1-001/lib
   [junit4]   2> 134492 T1402 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: lib (resolved as: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-1-001/lib).
   [junit4]   2> 134496 T1402 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 134498 T1402 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 134498 T1402 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 134498 T1402 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 134499 T1402 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
   [junit4]   2> 134499 T1430 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> 134499 T1441 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> 134499 T1402 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 134508 T1402 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 134508 T1402 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 134509 T1402 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 134513 T1402 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 134514 T1402 oashc.HttpShardHandlerFactory.getParameter Setting useRetries to: false
   [junit4]   2> 134514 T1402 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 134515 T1402 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 134515 T1402 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 134515 T1402 oasc.CoreContainer.load Node Name: 127.0.0.1
   [junit4]   2> 134515 T1402 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:46227/solr
   [junit4]   2> 134515 T1402 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 134516 T1402 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 134516 T1402 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 134518 T1455 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@cc60c2 name:ZooKeeperConnection Watcher:127.0.0.1:46227 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 134519 T1402 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 134519 T1402 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 134520 T1404 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x14c2f51d9c40005, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 134520 T1402 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 134522 T1458 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@120851a name:ZooKeeperConnection Watcher:127.0.0.1:46227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 134522 T1402 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 134537 T1402 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 134546 T1438 oasc.ZkController.register We are http://127.0.0.1:46366/collection1/ and leader is http://127.0.0.1:46366/collection1/
   [junit4]   2> 134546 T1438 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:46366
   [junit4]   2> 134546 T1438 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 134546 T1438 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 134546 T1438 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 134550 T1430 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 134550 T1431 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:46366",
   [junit4]   2> 	  "node_name":"127.0.0.1:46366_",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "operation":"state"} current state version: 2
   [junit4]   2> 134551 T1431 oasco.ReplicaMutator.updateState Update state numShards=3 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:46366",
   [junit4]   2> 	  "node_name":"127.0.0.1:46366_",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 134654 T1441 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> 134654 T1458 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> 134654 T1430 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> 135540 T1402 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34587_
   [junit4]   2> 135540 T1402 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:34587_
   [junit4]   2> 135543 T1402 oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 135545 T1402 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-1-001/cores
   [junit4]   1> CORE DESCRIPTOR: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, instanceDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-1-001/cores/collection1, collection=collection1, absoluteInstDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-1-001/cores/collection1/, coreNodeName=, dataDir=data/, shard=}
   [junit4]   2> 135546 T1402 oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-1-001/cores/collection1/
   [junit4]   2> 135546 T1402 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 135546 T1459 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 135547 T1459 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 135547 T1430 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 135547 T1459 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 135547 T1431 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:34587",
   [junit4]   2> 	  "node_name":"127.0.0.1:34587_",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"} current state version: 3
   [junit4]   2> 135548 T1431 oasco.ReplicaMutator.updateState Update state numShards=3 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:34587",
   [junit4]   2> 	  "node_name":"127.0.0.1:34587_",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 135548 T1431 oasco.ClusterStateMutator.createCollection building a new cName: collection1
   [junit4]   2> 135548 T1431 oasco.ReplicaMutator.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 135650 T1441 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> 135651 T1430 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> 135651 T1458 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> 136547 T1459 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 136548 T1459 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 136548 T1459 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 136548 T1459 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 136549 T1459 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 136550 T1459 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-1-001/cores/collection1/'
   [junit4]   2> 136559 T1459 oasc.ZkController.watchZKConfDir watch zkdir /configs/conf1
   [junit4]   2> 136563 T1459 oasc.Config.<init> loaded config solrconfig.xml with version 0 
   [junit4]   2> 136575 T1459 oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
   [junit4]   2> 136579 T1459 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 136588 T1459 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 136589 T1459 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 136594 T1459 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 136656 T1459 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 136658 T1459 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 136659 T1459 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 136662 T1459 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 136672 T1459 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 136672 T1459 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 136673 T1459 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-1-001/cores/collection1/, dataDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-1-001/cores/collection1/data/
   [junit4]   2> 136673 T1459 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d1bc4
   [junit4]   2> 136673 T1459 oasc.CachingDirectoryFactory.get return new directory for /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-1-001/cores/collection1/data
   [junit4]   2> 136674 T1459 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-1-001/cores/collection1/data/index/
   [junit4]   2> 136674 T1459 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-1-001/cores/collection1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 136677 T1459 oasc.CachingDirectoryFactory.get return new directory for /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-1-001/cores/collection1/data/index
   [junit4]   2> 136677 T1459 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=11, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1199888713279055]
   [junit4]   2> 136678 T1459 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@17886fc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ec2dc2),segFN=segments_1,generation=1}
   [junit4]   2> 136678 T1459 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 136682 T1459 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 136682 T1459 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 136682 T1459 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 136683 T1459 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 136683 T1459 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 136683 T1459 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 136683 T1459 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 136683 T1459 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 136683 T1459 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 136685 T1459 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 136686 T1459 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 136687 T1459 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 136688 T1459 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 136692 T1459 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> 136693 T1459 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 136701 T1459 oasu.UpdateHandler.<init> Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 136701 T1459 oasu.UpdateLog.init Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10
   [junit4]   2> 136702 T1459 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 136702 T1459 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 136703 T1459 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=49, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 136703 T1459 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@17886fc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1ec2dc2),segFN=segments_1,generation=1}
   [junit4]   2> 136704 T1459 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 136704 T1459 oass.SolrIndexSearcher.<init> Opening Searcher@123ea[collection1] main
   [junit4]   2> 136704 T1459 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 136705 T1459 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 136705 T1459 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 136705 T1459 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 136706 T1459 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 136706 T1459 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 136706 T1459 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 136706 T1459 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 136706 T1459 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 136707 T1459 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 136707 T1460 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@123ea[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 136707 T1459 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 136709 T1463 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:34587 collection:collection1 shard:shard2
   [junit4]   2> 136709 T1402 oass.SolrDispatchFilter.init user.dir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2
   [junit4]   2> 136709 T1402 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 136709 T1463 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 136711 T1463 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 136712 T1430 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 136712 T1463 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 136712 T1463 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C120 name=collection1 org.apache.solr.core.SolrCore@1ac1bf2 url=http://127.0.0.1:34587/collection1 node=127.0.0.1:34587_ C120_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=http://127.0.0.1:34587, node_name=127.0.0.1:34587_, state=down}
   [junit4]   2> 136712 T1463 C120 P34587 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:34587/collection1/
   [junit4]   2> 136712 T1431 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> 136712 T1463 C120 P34587 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 136713 T1463 C120 P34587 oasc.SyncStrategy.syncToMe http://127.0.0.1:34587/collection1/ has no replicas
   [junit4]   2> 136713 T1463 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:34587/collection1/ shard2
   [junit4]   2> 136713 T1463 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 136714 T1430 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 136715 T1431 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:34587",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "state":"active"} current state version: 4
   [junit4]   2> 136764 T1402 oas.SolrTestCaseJ4.writeCoreProperties Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-2-001/cores/collection1
   [junit4]   2> 136766 T1402 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2 in directory /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-2-001
   [junit4]   2> 136768 T1402 oejs.Server.doStart jetty-9.2.9.v20150224
   [junit4]   2> 136773 T1402 oejsh.ContextHandler.doStart Started o.e.j.s.ServletContextHandler@1415c1{/,null,AVAILABLE}
   [junit4]   2> 136775 T1402 oejs.AbstractConnector.doStart Started ServerConnector@e6039c{HTTP/1.1}{127.0.0.1:33310}
   [junit4]   2> 136775 T1402 oejs.Server.doStart Started @137565ms
   [junit4]   2> 136775 T1402 oascse.JettySolrRunner$1.lifeCycleStarted Jetty properties: {solr.data.dir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/tempDir-001/jetty2, solrconfig=solrconfig.xml, hostContext=/, hostPort=33310, coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-2-001/cores}
   [junit4]   2> 136776 T1402 oass.SolrDispatchFilter.init SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@6f3b58
   [junit4]   2> 136776 T1402 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-2-001/'
   [junit4]   2> 136790 T1402 oasc.SolrXmlConfig.fromFile Loading container configuration from /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-2-001/solr.xml
   [junit4]   2> 136794 T1402 oasc.CorePropertiesLocator.<init> Config-defined core root directory: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-2-001/cores
   [junit4]   2> 136794 T1402 oasc.CoreContainer.<init> New CoreContainer 13743000
   [junit4]   2> 136795 T1402 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-2-001/]
   [junit4]   2> 136795 T1402 oasc.CoreContainer.load loading shared library: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-2-001/lib
   [junit4]   2> 136795 T1402 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: lib (resolved as: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-2-001/lib).
   [junit4]   2> 136802 T1402 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 136802 T1402 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 136803 T1402 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 136803 T1402 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 136803 T1402 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
   [junit4]   2> 136803 T1402 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 136804 T1402 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 136804 T1402 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 136804 T1402 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 136804 T1402 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 136805 T1402 oashc.HttpShardHandlerFactory.getParameter Setting useRetries to: false
   [junit4]   2> 136805 T1402 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 136806 T1402 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 136806 T1402 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 136806 T1402 oasc.CoreContainer.load Node Name: 127.0.0.1
   [junit4]   2> 136807 T1402 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:46227/solr
   [junit4]   2> 136807 T1402 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 136807 T1402 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 136807 T1402 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 136809 T1477 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d5249a name:ZooKeeperConnection Watcher:127.0.0.1:46227 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 136810 T1402 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 136810 T1402 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 136816 T1441 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> 136816 T1458 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> 136816 T1430 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> 136822 T1463 oasc.ZkController.register We are http://127.0.0.1:34587/collection1/ and leader is http://127.0.0.1:34587/collection1/
   [junit4]   2> 136822 T1463 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:34587
   [junit4]   2> 136822 T1463 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 136822 T1463 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 136823 T1463 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 136823 T1430 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 136824 T1431 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:34587",
   [junit4]   2> 	  "node_name":"127.0.0.1:34587_",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"} current state version: 5
   [junit4]   2> 136825 T1431 oasco.ReplicaMutator.updateState Update state numShards=3 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:34587",
   [junit4]   2> 	  "node_name":"127.0.0.1:34587_",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 136829 T1402 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 136829 T1480 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19a4527 name:ZooKeeperConnection Watcher:127.0.0.1:46227/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 136830 T1402 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 136832 T1402 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 136929 T1430 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> 136929 T1458 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> 136929 T1441 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> 136929 T1480 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> 137834 T1402 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33310_
   [junit4]   2> 137834 T1402 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:33310_
   [junit4]   2> 137835 T1402 oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 137836 T1402 oasc.CorePropertiesLocator.discover Looking for core definitions underneath /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-2-001/cores
   [junit4]   1> CORE DESCRIPTOR: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, instanceDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-2-001/cores/collection1, collection=collection1, absoluteInstDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-2-001/cores/collection1/, coreNodeName=, dataDir=data/, shard=}
   [junit4]   2> 137837 T1402 oasc.CorePropertiesLocator.discoverUnder Found core collection1 in /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-2-001/cores/collection1/
   [junit4]   2> 137837 T1402 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 137838 T1481 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 137838 T1481 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 137838 T1430 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 137838 T1481 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 137838 T1431 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:33310",
   [junit4]   2> 	  "node_name":"127.0.0.1:33310_",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"} current state version: 6
   [junit4]   2> 137839 T1431 oasco.ReplicaMutator.updateState Update state numShards=3 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:33310",
   [junit4]   2> 	  "node_name":"127.0.0.1:33310_",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 137839 T1431 oasco.ReplicaMutator.updateState Collection already exists with numShards=3
   [junit4]   2> 137839 T1431 oasco.ReplicaMutator.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 137940 T1441 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 137940 T1430 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 137940 T1480 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 137940 T1458 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 138838 T1481 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 138839 T1481 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 138839 T1481 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 138839 T1481 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 138839 T1481 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 138840 T1481 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-2-001/cores/collection1/'
   [junit4]   2> 138847 T1481 oasc.ZkController.watchZKConfDir watch zkdir /configs/conf1
   [junit4]   2> 138848 T1481 oasc.Config.<init> loaded config solrconfig.xml with version 0 
   [junit4]   2> 138850 T1481 oasc.SolrConfig.refreshRequestParams current version of requestparams : -1
   [junit4]   2> 138852 T1481 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 138857 T1481 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 138858 T1481 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 138860 T1481 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 138907 T1481 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 138908 T1481 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 138908 T1481 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 138910 T1481 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 138915 T1481 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 138916 T1481 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 138916 T1481 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-2-001/cores/collection1/, dataDir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-2-001/cores/collection1/data/
   [junit4]   2> 138916 T1481 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3d1bc4
   [junit4]   2> 138917 T1481 oasc.CachingDirectoryFactory.get return new directory for /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-2-001/cores/collection1/data
   [junit4]   2> 138917 T1481 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-2-001/cores/collection1/data/index/
   [junit4]   2> 138917 T1481 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-2-001/cores/collection1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 138917 T1481 oasc.CachingDirectoryFactory.get return new directory for /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-2-001/cores/collection1/data/index
   [junit4]   2> 138918 T1481 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=11, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1199888713279055]
   [junit4]   2> 138918 T1481 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@afbbfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1b68440),segFN=segments_1,generation=1}
   [junit4]   2> 138918 T1481 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 138920 T1481 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 138921 T1481 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 138921 T1481 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 138921 T1481 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 138921 T1481 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 138921 T1481 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 138921 T1481 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 138921 T1481 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 138922 T1481 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 138923 T1481 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 138923 T1481 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 138924 T1481 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 138924 T1481 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 138927 T1481 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> 138927 T1481 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 138927 T1481 oasu.UpdateHandler.<init> Using UpdateLog implementation: org.apache.solr.update.UpdateLog
   [junit4]   2> 138927 T1481 oasu.UpdateLog.init Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10
   [junit4]   2> 138928 T1481 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 138928 T1481 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 138929 T1481 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=49, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 138929 T1481 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@afbbfc lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1b68440),segFN=segments_1,generation=1}
   [junit4]   2> 138929 T1481 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 138930 T1481 oass.SolrIndexSearcher.<init> Opening Searcher@1a9dc2d[collection1] main
   [junit4]   2> 138930 T1481 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 138930 T1481 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 138930 T1481 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 138930 T1481 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 138930 T1481 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 138931 T1481 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 138931 T1481 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 138931 T1481 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 138931 T1481 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 138931 T1481 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 138932 T1482 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1a9dc2d[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 138932 T1481 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 138932 T1485 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:33310 collection:collection1 shard:shard3
   [junit4]   2> 138932 T1402 oass.SolrDispatchFilter.init user.dir=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2
   [junit4]   2> 138933 T1402 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 138933 T1485 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 138934 T1485 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard3
   [junit4]   2> 138935 T1430 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 138935 T1485 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 138935 T1485 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C121 name=collection1 org.apache.solr.core.SolrCore@3645c2 url=http://127.0.0.1:33310/collection1 node=127.0.0.1:33310_ C121_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=http://127.0.0.1:33310, node_name=127.0.0.1:33310_, state=down}
   [junit4]   2> 138935 T1485 C121 P33310 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:33310/collection1/
   [junit4]   2> 138935 T1431 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard3",
   [junit4]   2> 	  "collection":"collection1"} current state version: 7
   [junit4]   2> 138935 T1485 C121 P33310 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 138935 T1485 C121 P33310 oasc.SyncStrategy.syncToMe http://127.0.0.1:33310/collection1/ has no replicas
   [junit4]   2> 138935 T1485 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:33310/collection1/ shard3
   [junit4]   2> 138943 T1485 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
   [junit4]   2> 138944 T1430 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 138945 T1431 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard3",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:33310",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "state":"active"} current state version: 7
   [junit4]   2> 139032 T1402 oas.SolrTestCaseJ4.writeCoreProperties Writing core.properties file to /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-3-001/cores/collection1
   [junit4]   2> 139041 T1402 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3 in directory /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-3-001
   [junit4]   2> 139042 T1402 oejs.Server.doStart jetty-9.2.9.v20150224
   [junit4]   2> 139043 T1402 oejsh.ContextHandler.doStart Started o.e.j.s.ServletContextHandler@131131a{/,null,AVAILABLE}
   [junit4]   2> 139044 T1402 oejs.Abs

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

lrCore@9dce25
   [junit4]   2> 176907 T1402 oasc.ZkController.unRegisterConfListener  a listener was removed because of core close
   [junit4]   2> 176907 T1402 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=4,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=2,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=184,transaction_logs_total_number=1}
   [junit4]   2> 176908 T1402 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 176908 T1402 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 176908 T1402 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 176909 T1402 oasc.SolrCore.closeSearcher [compositeid_collection_with_routerfield_shard2_replica2] Closing main searcher on request.
   [junit4]   2> 176919 T1402 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 176919 T1402 oasc.CachingDirectoryFactory.closeCacheValue looking to close /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-6-001/cores/compositeid_collection_with_routerfield_shard2_replica2/data [CachedDir<<refCount=0;path=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-6-001/cores/compositeid_collection_with_routerfield_shard2_replica2/data;done=false>>]
   [junit4]   2> 176920 T1402 oasc.CachingDirectoryFactory.close Closing directory: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-6-001/cores/compositeid_collection_with_routerfield_shard2_replica2/data
   [junit4]   2> 176920 T1402 oasc.CachingDirectoryFactory.closeCacheValue looking to close /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-6-001/cores/compositeid_collection_with_routerfield_shard2_replica2/data/index [CachedDir<<refCount=0;path=/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-6-001/cores/compositeid_collection_with_routerfield_shard2_replica2/data/index;done=false>>]
   [junit4]   2> 176920 T1402 oasc.CachingDirectoryFactory.close Closing directory: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/../../../../../../../../../home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001/shard-6-001/cores/compositeid_collection_with_routerfield_shard2_replica2/data/index
   [junit4]   2> 176921 T1402 oasc.Overseer.close Overseer (id=93501720860295184-127.0.0.1:45628_-n_0000000006) closing
   [junit4]   2> 176921 T1727 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:45628_
   [junit4]   2> 178422 T1574 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 178423 T1402 oejs.AbstractConnector.doStop Stopped ServerConnector@1629a9e{HTTP/1.1}{127.0.0.1:0}
   [junit4]   2> 178423 T1402 oejsh.ContextHandler.doStop Stopped o.e.j.s.ServletContextHandler@e7311e{/,null,UNAVAILABLE}
   [junit4]   2> 178425 T1402 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:46227 46227
   [junit4]   2> 178451 T1403 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:46227 46227
   [junit4]   2> 178453 T1403 oasc.ZkTestServer$ZKServerMain.runFromConfig WARN Watch limit violations: 
   [junit4]   2> 	Maximum concurrent create/delete watches above limit:
   [junit4]   2> 	
   [junit4]   2> 		14	/solr/aliases.json
   [junit4]   2> 		14	/solr/clusterstate.json
   [junit4]   2> 		7	/solr/configs/conf1
   [junit4]   2> 		4	/solr/collections/compositeid_collection_with_routerfield/state.json
   [junit4]   2> 		4	/solr/collections/implicit_collection_without_routerfield/state.json
   [junit4]   2> 	
   [junit4]   2> 	Maximum concurrent children watches above limit:
   [junit4]   2> 	
   [junit4]   2> 		14	/solr/live_nodes
   [junit4]   2> 		7	/solr/overseer/queue
   [junit4]   2> 		7	/solr/overseer/collection-queue-work
   [junit4]   2> 	
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=FullSolrCloudDistribCmdsTest -Dtests.method=test -Dtests.seed=93D2F7D5C020BCB5 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_AR -Dtests.timezone=BET -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
   [junit4] ERROR   45.6s J2 | FullSolrCloudDistribCmdsTest.test <<<
   [junit4]    > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrClient$RemoteSolrException: Error from server at http://127.0.0.1:34587/compositeid_collection_with_routerfield_shard1_replica1: no servers hosting shard: 
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([93D2F7D5C020BCB5:1B86C80F6EDCD14D]:0)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:584)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:236)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:228)
   [junit4]    > 	at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:135)
   [junit4]    > 	at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:943)
   [junit4]    > 	at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:958)
   [junit4]    > 	at org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.testDeleteByIdCompositeRouterWithRouterField(FullSolrCloudDistribCmdsTest.java:357)
   [junit4]    > 	at org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.test(FullSolrCloudDistribCmdsTest.java:146)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsFixedStatement.callStatement(BaseDistributedSearchTestCase.java:958)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:933)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 178495 T1402 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: /home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J2/temp/solr.cloud.FullSolrCloudDistribCmdsTest 93D2F7D5C020BCB5-001
   [junit4]   2> 45581 T1401 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
   [junit4]   2> NOTE: test params are: codec=Lucene50, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=es_AR, timezone=BET
   [junit4]   2> NOTE: Linux 3.13.0-46-generic i386/Oracle Corporation 1.9.0-ea (32-bit)/cpus=12,threads=1,free=93043968,total=269484032
   [junit4]   2> NOTE: All tests run in this JVM: [CursorMarkTest, PrimUtilsTest, TestBinaryResponseWriter, SampleTest, TestPseudoReturnFields, TestXIncludeConfig, TermVectorComponentDistributedTest, DistanceUnitsTest, PolyFieldTest, NotRequiredUniqueKeyTest, SearchHandlerTest, TestOverriddenPrefixQueryForCustomFieldType, AssignTest, OpenExchangeRatesOrgProviderTest, TestInitQParser, TestFastOutputStream, OverseerTest, TestExtendedDismaxParser, TestSearcherReuse, SimpleFacetsTest, TestCollectionAPI, TestExactStatsCache, TestSurroundQueryParser, ChangedSchemaMergeTest, RecoveryZkTest, CoreAdminRequestStatusTest, TestFieldTypeResource, TestFieldTypeCollectionResource, TestObjectReleaseTracker, TestLeaderElectionZkExpiry, TestSchemaVersionResource, DirectSolrSpellCheckerTest, TestStressReorder, DistributedFacetPivotSmallAdvancedTest, FullSolrCloudDistribCmdsTest]
   [junit4] Completed on J2 in 46.61s, 1 test, 1 error <<< FAILURES!

[...truncated 1299 lines...]
BUILD FAILED
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:519: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:467: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:61: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:39: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:191: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:510: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1351: The following error occurred while executing this line:
/home/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:958: There were test failures: 475 suites, 1891 tests, 1 error, 48 ignored (21 assumptions)

Total time: 36 minutes 45 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 32bit/jdk1.9.0-ea-b47 -server -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any