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 2014/04/04 00:19:58 UTC

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

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

1 tests failed.
REGRESSION:  org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDistribSearch

Error Message:
reloadcollection the collection time out:180s

Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: reloadcollection the collection time out:180s
	at __randomizedtesting.SeedInfo.seed([B3F57B521B6ED17C:3213F54A6C31B140]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:554)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:210)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:206)
	at org.apache.solr.client.solrj.request.CollectionAdminRequest.process(CollectionAdminRequest.java:300)
	at org.apache.solr.client.solrj.request.CollectionAdminRequest.reloadCollection(CollectionAdminRequest.java:425)
	at org.apache.solr.client.solrj.request.CollectionAdminRequest.reloadCollection(CollectionAdminRequest.java:416)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testSolrJAPICalls(CollectionsAPIDistributedZkTest.java:302)
	at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:201)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:867)
	at sun.reflect.GeneratedMethodAccessor36.invoke(Unknown Source)
	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:1617)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
	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.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	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:359)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
	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 org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	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 org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	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:359)
	at java.lang.Thread.run(Thread.java:744)




Build Log:
[...truncated 10963 lines...]
   [junit4] Suite: org.apache.solr.cloud.CollectionsAPIDistributedZkTest
   [junit4]   2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1396561688287
   [junit4]   2> 1444958 T6185 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
   [junit4]   2> 1444958 T6185 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /kqsp/
   [junit4]   2> 1444961 T6185 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> 1444963 T6185 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 1444965 T6186 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1445066 T6185 oasc.ZkTestServer.run start zk server on port:50782
   [junit4]   2> 1445067 T6185 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1445075 T6192 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18426892 name:ZooKeeperConnection Watcher:127.0.0.1:50782 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1445093 T6185 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1445094 T6185 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1445121 T6185 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1445125 T6194 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18ba9b01 name:ZooKeeperConnection Watcher:127.0.0.1:50782/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1445126 T6185 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1445126 T6185 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 1445133 T6185 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 1445139 T6185 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 1445146 T6185 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 1445153 T6185 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 1445154 T6185 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 1445163 T6185 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 1445164 T6185 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 1445170 T6185 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1445171 T6185 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1445176 T6185 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 1445177 T6185 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 1445183 T6185 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 1445183 T6185 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 1445191 T6185 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 1445191 T6185 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 1445199 T6185 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 1445200 T6185 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 1445207 T6185 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1445207 T6185 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1445215 T6185 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1445215 T6185 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1445221 T6185 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 1445222 T6185 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 1445229 T6185 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 1445229 T6185 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> Using old style solr.xml
   [junit4]   2> 1446865 T6185 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1446874 T6185 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50785
   [junit4]   2> 1446874 T6185 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1446875 T6185 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1446875 T6185 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1396561688568
   [junit4]   2> 1446875 T6185 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1396561688568/'
   [junit4]   2> 1446921 T6185 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1396561688568/solr.xml
   [junit4]   2> 1446936 T6185 oasc.CoreContainer.<init> New CoreContainer 735814061
   [junit4]   2> 1446936 T6185 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1396561688568/]
   [junit4]   2> 1446937 T6185 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1446937 T6185 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
   [junit4]   2> 1446937 T6185 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1446938 T6185 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1446938 T6185 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1446939 T6185 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1446939 T6185 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1446939 T6185 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1446940 T6185 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1446940 T6185 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1446940 T6185 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1446941 T6185 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1446941 T6185 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50782/solr
   [junit4]   2> 1446941 T6185 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1446943 T6185 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1446946 T6205 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@58a0adf2 name:ZooKeeperConnection Watcher:127.0.0.1:50782 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1446946 T6185 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1446951 T6185 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1446955 T6207 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3825d456 name:ZooKeeperConnection Watcher:127.0.0.1:50782/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1446955 T6185 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1446959 T6185 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1446967 T6185 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1446974 T6185 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 1446981 T6185 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 1446989 T6185 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 1446997 T6185 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1447001 T6185 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50785_kqsp
   [junit4]   2> 1447004 T6185 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50785_kqsp
   [junit4]   2> 1447011 T6185 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1447016 T6185 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1447025 T6185 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:50785_kqsp
   [junit4]   2> 1447025 T6185 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1447031 T6185 oasc.Overseer.start Overseer (id=91525066804428803-127.0.0.1:50785_kqsp-n_0000000000) starting
   [junit4]   2> 1447039 T6185 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1447069 T6209 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1447070 T6185 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1447071 T6209 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:50785_kqsp
   [junit4]   2> 1447074 T6185 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1447078 T6185 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1447086 T6208 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1447090 T6185 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1447090 T6185 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1447091 T6185 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1447094 T6212 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@396d12a2 name:ZooKeeperConnection Watcher:127.0.0.1:50782/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1447094 T6185 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1447096 T6185 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1447102 T6185 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 1448706 T6185 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 1448707 T6185 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1448711 T6185 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50789
   [junit4]   2> 1448712 T6185 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1448712 T6185 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1448712 T6185 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1396561690433
   [junit4]   2> 1448713 T6185 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1396561690433/'
   [junit4]   2> 1448749 T6185 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1396561690433/solr.xml
   [junit4]   2> 1448763 T6185 oasc.CoreContainer.<init> New CoreContainer 1738667645
   [junit4]   2> 1448763 T6185 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1396561690433/]
   [junit4]   2> 1448763 T6185 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1448764 T6185 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
   [junit4]   2> 1448764 T6185 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1448764 T6185 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1448765 T6185 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1448765 T6185 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1448765 T6185 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1448766 T6185 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1448766 T6185 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1448766 T6185 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1448767 T6185 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1448767 T6185 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1448768 T6185 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50782/solr
   [junit4]   2> 1448768 T6185 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1448769 T6185 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1448773 T6223 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7719978d name:ZooKeeperConnection Watcher:127.0.0.1:50782 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1448774 T6185 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1448778 T6185 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1448781 T6225 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11f60896 name:ZooKeeperConnection Watcher:127.0.0.1:50782/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1448781 T6185 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1448798 T6185 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1449806 T6185 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50789_kqsp
   [junit4]   2> 1449810 T6185 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50789_kqsp
   [junit4]   2> 1449816 T6225 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1449817 T6212 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1449817 T6207 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1449828 T6185 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1449828 T6185 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1451295 T6185 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 1451296 T6185 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1451302 T6185 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50792
   [junit4]   2> 1451302 T6185 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1451302 T6185 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1451303 T6185 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1396561693160
   [junit4]   2> 1451303 T6185 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1396561693160/'
   [junit4]   2> 1451346 T6185 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1396561693160/solr.xml
   [junit4]   2> 1451371 T6185 oasc.CoreContainer.<init> New CoreContainer 1813299554
   [junit4]   2> 1451372 T6185 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1396561693160/]
   [junit4]   2> 1451373 T6185 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1451373 T6185 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
   [junit4]   2> 1451374 T6185 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1451374 T6185 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1451374 T6185 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1451375 T6185 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1451375 T6185 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1451375 T6185 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1451376 T6185 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1451376 T6185 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1451377 T6185 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1451377 T6185 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1451377 T6185 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50782/solr
   [junit4]   2> 1451377 T6185 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1451379 T6185 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1451383 T6237 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7f928bcc name:ZooKeeperConnection Watcher:127.0.0.1:50782 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1451384 T6185 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1451389 T6185 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1451391 T6239 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@58061a37 name:ZooKeeperConnection Watcher:127.0.0.1:50782/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1451392 T6185 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1451409 T6185 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1452418 T6185 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50792_kqsp
   [junit4]   2> 1452420 T6185 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50792_kqsp
   [junit4]   2> 1452428 T6212 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1452428 T6207 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1452428 T6225 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1452428 T6239 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1452442 T6185 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1452443 T6185 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1453977 T6185 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
   [junit4]   2> 1453978 T6185 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1453983 T6185 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50795
   [junit4]   2> 1453983 T6185 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1453984 T6185 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1453984 T6185 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1396561695774
   [junit4]   2> 1453984 T6185 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1396561695774/'
   [junit4]   2> 1454017 T6185 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1396561695774/solr.xml
   [junit4]   2> 1454034 T6185 oasc.CoreContainer.<init> New CoreContainer 1364821684
   [junit4]   2> 1454034 T6185 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1396561695774/]
   [junit4]   2> 1454035 T6185 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1454035 T6185 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
   [junit4]   2> 1454035 T6185 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1454035 T6185 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1454036 T6185 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1454037 T6185 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1454037 T6185 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1454037 T6185 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1454038 T6185 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1454038 T6185 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1454038 T6185 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1454039 T6185 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1454039 T6185 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50782/solr
   [junit4]   2> 1454040 T6185 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1454041 T6185 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1454046 T6251 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@43bc9c96 name:ZooKeeperConnection Watcher:127.0.0.1:50782 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1454046 T6185 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1454053 T6185 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1454054 T6253 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@12d89201 name:ZooKeeperConnection Watcher:127.0.0.1:50782/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1454055 T6185 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1454073 T6185 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1455082 T6185 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50795_kqsp
   [junit4]   2> 1455084 T6185 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50795_kqsp
   [junit4]   2> 1455090 T6225 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1455090 T6253 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1455090 T6207 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1455091 T6212 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1455092 T6239 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1455101 T6185 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1455102 T6185 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1456602 T6185 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 4
   [junit4]   2> 1456602 T6185 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1456606 T6185 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50798
   [junit4]   2> 1456607 T6185 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1456607 T6185 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1456607 T6185 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1396561698433
   [junit4]   2> 1456608 T6185 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1396561698433/'
   [junit4]   2> 1456642 T6185 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1396561698433/solr.xml
   [junit4]   2> 1456653 T6185 oasc.CoreContainer.<init> New CoreContainer 1653631836
   [junit4]   2> 1456654 T6185 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1396561698433/]
   [junit4]   2> 1456654 T6185 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 1456655 T6185 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
   [junit4]   2> 1456655 T6185 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1456655 T6185 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1456656 T6185 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1456657 T6185 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1456657 T6185 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1456657 T6185 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1456657 T6185 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1456658 T6185 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1456658 T6185 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1456659 T6185 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1456659 T6185 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50782/solr
   [junit4]   2> 1456659 T6185 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1456661 T6185 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1456665 T6265 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14912b92 name:ZooKeeperConnection Watcher:127.0.0.1:50782 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1456666 T6185 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1456671 T6185 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1456673 T6267 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@43ce6f0e name:ZooKeeperConnection Watcher:127.0.0.1:50782/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1456673 T6185 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1456691 T6185 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1457699 T6185 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50798_kqsp
   [junit4]   2> 1457702 T6185 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50798_kqsp
   [junit4]   2> 1457708 T6253 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1457709 T6239 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1457709 T6207 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1457709 T6212 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1457709 T6267 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1457709 T6225 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 1457721 T6185 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1457721 T6185 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1457725 T6219 oasha.CollectionsHandler.handleCreateAction Creating Collection : replicationFactor=2&collection.configName=conf1&router.field=myOwnField&name=solrj_collection&router.name=compositeId&action=CREATE&numShards=2&wt=javabin&version=2
   [junit4]   2> 1457727 T6207 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/collection-queue-work state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1457729 T6209 oasc.OverseerCollectionProcessor.run Overseer Collection Processor: Get the message id:/overseer/collection-queue-work/qn-0000000000 message:{
   [junit4]   2> 	  "operation":"createcollection",
   [junit4]   2> 	  "fromApi":"true",
   [junit4]   2> 	  "name":"solrj_collection",
   [junit4]   2> 	  "replicationFactor":"2",
   [junit4]   2> 	  "collection.configName":"conf1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "router.field":"myOwnField",
   [junit4]   2> 	  "router.name":"compositeId"}
   [junit4]   2> 1457730 T6209 oasc.OverseerCollectionProcessor.processMessage WARN OverseerCollectionProcessor.processMessage : createcollection , {
   [junit4]   2> 	  "operation":"createcollection",
   [junit4]   2> 	  "fromApi":"true",
   [junit4]   2> 	  "name":"solrj_collection",
   [junit4]   2> 	  "replicationFactor":"2",
   [junit4]   2> 	  "collection.configName":"conf1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "router.field":"myOwnField",
   [junit4]   2> 	  "router.name":"compositeId"}
   [junit4]   2> 1457731 T6209 oasc.OverseerCollectionProcessor.createConfNode creating collections conf node /collections/solrj_collection 
   [junit4]   2> 1457731 T6209 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection
   [junit4]   2> 1457741 T6207 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1457744 T6208 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1457745 T6208 oasc.Overseer$ClusterStateUpdater.buildCollection building a new collection: solrj_collection
   [junit4]   2> 1457745 T6208 oasc.Overseer$ClusterStateUpdater.createCollection Create collection solrj_collection with shards [shard1, shard2]
   [junit4]   2> 1457751 T6207 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1457754 T6207 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1457754 T6212 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1457758 T6253 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1457761 T6225 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1457762 T6267 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1457763 T6239 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1457842 T6209 oasc.OverseerCollectionProcessor.createCollection Creating SolrCores for new collection, shardNames [shard1, shard2] , replicationFactor : 2
   [junit4]   2> 1457842 T6209 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica1 as part of slice shard1 of collection solrj_collection on 127.0.0.1:50792_kqsp
   [junit4]   2> 1457844 T6209 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard1_replica2 as part of slice shard1 of collection solrj_collection on 127.0.0.1:50789_kqsp
   [junit4]   2> 1457848 T6209 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica1 as part of slice shard2 of collection solrj_collection on 127.0.0.1:50785_kqsp
   [junit4]   2> 1457850 T6234 oasha.CoreAdminHandler.handleCreateAction core create command qt=/admin/cores&collection.configName=conf1&name=solrj_collection_shard1_replica1&action=CREATE&numShards=2&collection=solrj_collection&shard=shard1&wt=javabin&version=2
   [junit4]   2> 1457852 T6220 oasha.CoreAdminHandler.handleCreateAction core create command qt=/admin/cores&collection.configName=conf1&name=solrj_collection_shard1_replica2&action=CREATE&numShards=2&collection=solrj_collection&shard=shard1&wt=javabin&version=2
   [junit4]   2> 1457853 T6209 oasc.OverseerCollectionProcessor.createCollection Creating shard solrj_collection_shard2_replica2 as part of slice shard2 of collection solrj_collection on 127.0.0.1:50795_kqsp
   [junit4]   2> 1457856 T6201 oasha.CoreAdminHandler.handleCreateAction core create command qt=/admin/cores&collection.configName=conf1&name=solrj_collection_shard2_replica1&action=CREATE&numShards=2&collection=solrj_collection&shard=shard2&wt=javabin&version=2
   [junit4]   2> 1457857 T6220 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica2 state=down collection=solrj_collection
   [junit4]   2> 1457857 T6234 oasc.ZkController.publish publishing core=solrj_collection_shard1_replica1 state=down collection=solrj_collection
   [junit4]   2> 1457861 T6220 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1457861 T6247 oasha.CoreAdminHandler.handleCreateAction core create command qt=/admin/cores&collection.configName=conf1&name=solrj_collection_shard2_replica2&action=CREATE&numShards=2&collection=solrj_collection&shard=shard2&wt=javabin&version=2
   [junit4]   2> 1457862 T6207 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1457863 T6201 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica1 state=down collection=solrj_collection
   [junit4]   2> 1457864 T6234 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1457865 T6207 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1457866 T6247 oasc.ZkController.publish publishing core=solrj_collection_shard2_replica2 state=down collection=solrj_collection
   [junit4]   2> 1457865 T6201 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1457867 T6208 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1457868 T6247 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1457869 T6208 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50789/kqsp",
   [junit4]   2> 	  "core":"solrj_collection_shard1_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50789_kqsp",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1457877 T6208 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50792/kqsp",
   [junit4]   2> 	  "core":"solrj_collection_shard1_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50792_kqsp",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1457883 T6207 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1457885 T6208 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50785/kqsp",
   [junit4]   2> 	  "core":"solrj_collection_shard2_replica1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50785_kqsp",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1457890 T6207 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1457892 T6208 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50795/kqsp",
   [junit4]   2> 	  "core":"solrj_collection_shard2_replica2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50795_kqsp",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"solrj_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1457896 T6207 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1458002 T6207 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1458002 T6267 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1458003 T6239 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1458003 T6225 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1458003 T6212 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1458002 T6253 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 1458863 T6220 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica2
   [junit4]   2> 1458864 T6220 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1396561690433/solr.xml
   [junit4]   2> 1458864 T6220 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 1458866 T6234 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard1_replica1
   [junit4]   2> 1458866 T6220 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1458867 T6220 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 1458867 T6234 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1396561693160/solr.xml
   [junit4]   2> 1458868 T6234 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 1458869 T6201 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica1
   [junit4]   2> 1458870 T6247 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for solrj_collection_shard2_replica2
   [junit4]   2> 1458870 T6201 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1396561688568/solr.xml
   [junit4]   2> 1458872 T6201 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 1458872 T6234 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1458873 T6234 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 1458873 T6201 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1458874 T6201 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 1458871 T6247 oasc.SolrXMLCoresLocator.doPersist Persisted core descriptions to /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1396561695774/solr.xml
   [junit4]   2> 1458875 T6247 oasc.ZkController.createCollectionZkNode Check for collection zkNode:solrj_collection
   [junit4]   2> 1458875 T6234 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1458876 T6234 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1396561693160/solrj_collection_shard1_replica1/'
   [junit4]   2> 1458877 T6201 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1458877 T6201 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1396561688568/solrj_collection_shard2_replica1/'
   [junit4]   2> 1458872 T6220 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1458879 T6220 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1396561690433/solrj_collection_shard1_replica2/'
   [junit4]   2> 1458879 T6247 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1458882 T6247 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 1458902 T6247 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1458903 T6247 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1396561695774/solrj_collection_shard2_replica2/'
   [junit4]   2> 1458940 T6220 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1458952 T6234 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1458953 T6220 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1458973 T6234 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1458990 T6201 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1459007 T6201 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1459011 T6234 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1459018 T6234 oass.IndexSchema.readSchema [solrj_collection_shard1_replica1] Schema name=test
   [junit4]   2> 1459022 T6220 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1459023 T6201 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1459029 T6247 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1459053 T6247 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1459058 T6220 oass.IndexSchema.readSchema [solrj_collection_shard1_replica2] Schema name=test
   [junit4]   2> 1459062 T6201 oass.IndexSchema.readSchema [solrj_collection_shard2_replica1] Schema name=test
   [junit4]   2> 1459086 T6247 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1459092 T6247 oass.IndexSchema.readSchema [solrj_collection_shard2_replica2] Schema name=test
   [junit4]   2> 1459368 T6234 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1459391 T6220 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1459392 T6234 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1459397 T6220 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1459399 T6220 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1459401 T6234 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1459441 T6247 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1459458 T6247 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1459465 T6234 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1459467 T6201 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1459472 T6234 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1459476 T6201 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1459477 T6247 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1459477 T6201 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1459483 T6234 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1459479 T6220 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1459491 T6220 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1459493 T6234 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1459494 T6234 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1459494 T6234 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1459499 T6220 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1459501 T6234 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1459501 T6234 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1459502 T6234 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica1' using configuration from collection solrj_collection
   [junit4]   2> 1459502 T6234 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1459502 T6234 oasc.SolrCore.<init> [solrj_collection_shard1_replica1] Opening new SolrCore at ./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1396561693160/solrj_collection_shard1_replica1/, dataDir=./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1396561693160/solrj_collection_shard1_replica1/data/
   [junit4]   2> 1459503 T6220 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1459504 T6220 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1459505 T6220 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1459504 T6234 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@45274d77
   [junit4]   2> 1459508 T6220 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1459508 T6220 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1459508 T6220 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard1_replica2' using configuration from collection solrj_collection
   [junit4]   2> 1459509 T6220 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1459510 T6220 oasc.SolrCore.<init> [solrj_collection_shard1_replica2] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1396561690433/solrj_collection_shard1_replica2/, dataDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1396561690433/solrj_collection_shard1_replica2/data/
   [junit4]   2> 1459511 T6220 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@45274d77
   [junit4]   2> 1459509 T6234 oasc.CachingDirectoryFactory.get return new directory for ./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1396561693160/solrj_collection_shard1_replica1/data
   [junit4]   2> 1459512 T6234 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1396561693160/solrj_collection_shard1_replica1/data/index/
   [junit4]   2> 1459513 T6234 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica1] Solr index directory './solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1396561693160/solrj_collection_shard1_replica1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1459512 T6220 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1396561690433/solrj_collection_shard1_replica2/data
   [junit4]   2> 1459514 T6220 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1396561690433/solrj_collection_shard1_replica2/data/index/
   [junit4]   2> 1459515 T6220 oasc.SolrCore.initIndex WARN [solrj_collection_shard1_replica2] Solr index directory '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1396561690433/solrj_collection_shard1_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1459515 T6234 oasc.CachingDirectoryFactory.get return new directory for ./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty2-1396561693160/solrj_collection_shard1_replica1/data/index
   [junit4]   2> 1459516 T6234 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1201901374, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 1459517 T6220 oasc.CachingDirectoryFactory.get return new directory for ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty1-1396561690433/solrj_collection_shard1_replica2/data/index
   [junit4]   2> 1459520 T6220 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1201901374, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 1459521 T6234 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@738e139c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@709fdc9d),segFN=segments_1,generation=1}
   [junit4]   2> 1459521 T6234 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1459527 T6234 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1459528 T6234 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1459529 T6247 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1459528 T6220 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@7c1c5196 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@320fec7),segFN=segments_1,generation=1}
   [junit4]   2> 1459530 T6220 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1459529 T6234 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1459532 T6234 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1459533 T6234 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1459539 T6234 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1459541 T6220 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1459542 T6220 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1459542 T6220 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1459542 T6220 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1459543 T6220 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1459543 T6220 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1459544 T6220 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1459545 T6220 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1459545 T6220 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1459546 T6220 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1459547 T6234 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1459547 T6220 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1459548 T6220 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1459548 T6220 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1459549 T6220 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1459549 T6220 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1459550 T6220 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1459550 T6220 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 1459547 T6234 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1459551 T6234 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1459551 T6234 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1459552 T6234 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1459552 T6234 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1459553 T6234 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1459553 T6234 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1459554 T6234 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1459554 T6234 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1459555 T6234 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 1459550 T6247 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1459559 T6234 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1459560 T6220 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1459565 T6247 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1459567 T6234 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1459568 T6234 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1459568 T6220 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1459569 T6220 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1459569 T6234 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1884517103, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 1459569 T6201 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1459572 T6247 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1459572 T6247 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1459573 T6247 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1459571 T6234 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@738e139c lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@709fdc9d),segFN=segments_1,generation=1}
   [junit4]   2> 1459574 T6234 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1459574 T6234 oass.SolrIndexSearcher.<init> Opening Searcher@7065f1f8[solrj_collection_shard1_replica1] main
   [junit4]   2> 1459574 T6234 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 1459576 T6201 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1459571 T6220 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1884517103, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 1459579 T6220 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@7c1c5196 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@320fec7),segFN=segments_1,generation=1}
   [junit4]   2> 1459579 T6220 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1459579 T6220 oass.SolrIndexSearcher.<init> Opening Searcher@40fca84c[solrj_collection_shard1_replica2] main
   [junit4]   2> 1459580 T6220 oascc.ZkStateReader.readConfigName Load collection config from:/collections/solrj_collection
   [junit4]   2> 1459580 T6234 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1459580 T6234 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 1459580 T6201 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1459580 T6247 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1459582 T6247 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1459582 T6247 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica2' using configuration from collection solrj_collection
   [junit4]   2> 1459583 T6247 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1459583 T6247 oasc.SolrCore.<init> [solrj_collection_shard2_replica2] Opening new SolrCore at ./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1396561695774/solrj_collection_shard2_replica2/, dataDir=./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1396561695774/solrj_collection_shard2_replica2/data/
   [junit4]   2> 1459584 T6247 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@45274d77
   [junit4]   2> 1459582 T6234 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1459584 T6234 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 1459583 T6201 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1459585 T6201 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1459585 T6201 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1459585 T6220 oascc.ZkStateReader.readConfigName path=/collections/solrj_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1459586 T6220 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 1459584 T6234 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1459585 T6247 oasc.CachingDirectoryFactory.get return new directory for ./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1396561695774/solrj_collection_shard2_replica2/data
   [junit4]   2> 1459588 T6247 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1396561695774/solrj_collection_shard2_replica2/data/index/
   [junit4]   2> 1459588 T6247 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica2] Solr index directory './solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1396561695774/solrj_collection_shard2_replica2/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1459587 T6220 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1459589 T6220 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 1459587 T6201 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1459590 T6201 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1459590 T6201 oasc.CoreContainer.create Creating SolrCore 'solrj_collection_shard2_replica1' using configuration from collection solrj_collection
   [junit4]   2> 1459591 T6201 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1459590 T6220 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1459589 T6247 oasc.CachingDirectoryFactory.get return new directory for ./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty3-1396561695774/solrj_collection_shard2_replica2/data/index
   [junit4]   2> 1459592 T6220 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 1459588 T6234 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 1459593 T6234 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1459593 T6234 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 1459594 T6234 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 1459593 T6220 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1459595 T6220 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 1459595 T6220 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 1459592 T6247 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1201901374, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 1459591 T6201 oasc.SolrCore.<init> [solrj_collection_shard2_replica1] Opening new SolrCore at ./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1396561688568/solrj_collection_shard2_replica1/, dataDir=./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1396561688568/solrj_collection_shard2_replica1/data/
   [junit4]   2> 1459597 T6273 oasc.SolrCore.registerSearcher [solrj_collection_shard1_replica1] Registered new searcher Searcher@7065f1f8[solrj_collection_shard1_replica1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1459598 T6274 oasc.SolrCore.registerSearcher [solrj_collection_shard1_replica2] Registered new searcher Searcher@40fca84c[solrj_collection_shard1_replica2] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1459598 T6201 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@45274d77
   [junit4]   2> 1459600 T6234 oasc.CoreContainer.registerCore registering core: solrj_collection_shard1_replica1
   [junit4]   2> 1459600 T6234 oasc.ZkController.register Register replica - core:solrj_collection_shard1_replica1 address:http://127.0.0.1:50792/kqsp collection:solrj_collection shard:shard1
   [junit4]   2> 1459601 T6247 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@5c4afad7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@783f9b45),segFN=segments_1,generation=1}
   [junit4]   2> 1459601 T6247 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1459601 T6220 oasc.CoreContainer.registerCore registering core: solrj_collection_shard1_replica2
   [junit4]   2> 1459603 T6220 oasc.ZkController.register Register replica - core:solrj_collection_shard1_replica2 address:http://127.0.0.1:50789/kqsp collection:solrj_collection shard:shard1
   [junit4]   2> 1459601 T6201 oasc.CachingDirectoryFactory.get return new directory for ./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1396561688568/solrj_collection_shard2_replica1/data
   [junit4]   2> 1459604 T6201 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1396561688568/solrj_collection_shard2_replica1/data/index/
   [junit4]   2> 1459604 T6201 oasc.SolrCore.initIndex WARN [solrj_collection_shard2_replica1] Solr index directory './solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1396561688568/solrj_collection_shard2_replica1/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1459605 T6201 oasc.CachingDirectoryFactory.get return new directory for ./solrtest-CollectionsAPIDistributedZkTest-1396561688287/org.apache.solr.cloud.CollectionsAPIDistributedZkTest-controljetty-1396561688568/solrj_collection_shard2_replica1/data/index
   [junit4]   2> 1459606 T6201 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1201901374, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 1459606 T6247 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1459607 T6247 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1459608 T6201 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@249e90b1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5f173a73),segFN=segments_1,generation=1}
   [junit4]   2> 1459608 T6201 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1459608 T6247 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1459609 T6247 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1459610 T6247 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1459610 T6247 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1459610 T6247 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1459611 T6247 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1459611 T6247 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1459611 T6201 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1459612 T6220 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard1/election
   [junit4]   2> 1459612 T6234 oascc.SolrZkClient.makePath makePath: /collections/solrj_collection/leader_elect/shard1/election
   [junit4]   2> 1459612 T6247 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1459612 T6201 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1459615 T6201 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1459616 T6201 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1459616 T6201 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1459614 T6247 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1459618 T6247 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1459618 T6247 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1459618 T6247 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1459619 T6247 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1459619 T6247 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1459620 T6247 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 1459616 T6201 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1459621 T6201 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1459621 T6201 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1459622 T6201 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1459622 T6247 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1459622 T6201 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1459624 T6201 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1459625 T6201 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1459626 T6201 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1459626 T6201 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1459626 T6201 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1459627 T6201 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1459628 T6247 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1459628 T6247 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1459629 T6247 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1884517103, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 1459628 T6201 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr

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

unit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> 
   [junit4]   2> 1650731 T6319 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
   [junit4]   2> 
   [junit4]   2> 1650733 T6239 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 1651133 T6323 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:302)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:85)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:291)
   [junit4]   2> 
   [junit4]   2> 1651135 T6267 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> NOTE: test params are: codec=Lucene42, sim=DefaultSimilarity, locale=ro_RO, timezone=Asia/Ujung_Pandang
   [junit4]   2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.8.0 (64-bit)/cpus=2,threads=1,free=61451136,total=228696064
   [junit4]   2> NOTE: All tests run in this JVM: [TestReplicationHandler, TestSolrQueryParserResource, DistributedSuggestComponentTest, ZkControllerTest, ConvertedLegacyTest, HdfsRecoveryZkTest, TestImplicitCoreProperties, ModifyConfFileTest, ResponseLogComponentTest, DOMUtilTest, TestCollectionAPI, TestClassNameShortening, SynonymTokenizerTest, BadCopyFieldTest, TestSolrJ, TestFaceting, TestReloadAndDeleteDocs, XmlUpdateRequestHandlerTest, DistribCursorPagingTest, NoFacetTest, TestSolrDeletionPolicy2, HdfsCollectionsAPIDistributedZkTest, TestCollationField, TestDistributedGrouping, TestPerFieldSimilarity, OverseerTest, SolrIndexSplitterTest, StandardRequestHandlerTest, BadComponentTest, TestSolrXml, TestPostingsSolrHighlighter, SolrPluginUtilsTest, PluginInfoTest, CurrencyFieldXmlFileTest, TestHighlightDedupGrouping, TestFieldTypeResource, PathHierarchyTokenizerFactoryTest, DisMaxRequestHandlerTest, HdfsUnloadDistributedZkTest, HighlighterTest, TestStressLucene, TestElisionMultitermQuery, ShardRoutingCustomTest, OverseerStatusTest, TestShardHandlerFactory, TestManagedSchema, TestWordDelimiterFilterFactory, MinimalSchemaTest, TestDynamicFieldCollectionResource, QueryParsingTest, TestRestManager, TestSearcherReuse, DocumentBuilderTest, CursorMarkTest, TestCopyFieldCollectionResource, RequiredFieldsTest, TestSolrXmlPersistor, TestFieldSortValues, UnloadDistributedZkTest, TestManagedResourceStorage, TestCollationFieldDocValues, TestRTGBase, TermsComponentTest, ZkSolrClientTest, StatsComponentTest, UpdateRequestProcessorFactoryTest, FieldFacetExtrasTest, TestBinaryField, LoggingHandlerTest, DistributedQueryElevationComponentTest, TestUniqueKeyFieldResource, DistributedQueryComponentOptimizationTest, TestRangeQuery, TestStressRecovery, TestGroupingSearch, TestRecovery, LeaderElectionIntegrationTest, DistributedExpandComponentTest, TestZkChroot, TestSolrQueryParser, StressHdfsTest, AssignTest, JSONWriterTest, SignatureUpdateProcessorFactoryTest, TestAnalyzedSuggestions, TestBlendedInfixSuggestions, TestManagedSchemaFieldResource, TestCoreContainer, TestSuggestSpellingConverter, SolrTestCaseJ4Test, TestQueryTypes, MoreLikeThisHandlerTest, HdfsSyncSliceTest, HdfsBasicDistributedZkTest, TermVectorComponentTest, XsltUpdateRequestHandlerTest, HardAutoCommitTest, TestSurroundQueryParser, TestLRUCache, TestCustomSort, TestExceedMaxTermLength, TestFieldResource, DocValuesTest, TestCoreDiscovery, CacheHeaderTest, TestSchemaNameResource, AnalysisErrorHandlingTest, TestDynamicFieldResource, SolrInfoMBeanTest, EnumFieldTest, CoreMergeIndexesAdminHandlerTest, FieldMutatingUpdateProcessorTest, IndexSchemaRuntimeFieldTest, URLClassifyProcessorTest, TestSolrXMLSerializer, PolyFieldTest, TestSort, DistributedTermsComponentTest, ConnectionManagerTest, QueryResultKeyTest, CSVRequestHandlerTest, FieldAnalysisRequestHandlerTest, PreAnalyzedFieldTest, TestSolrQueryParserDefaultOperatorResource, SolrCoreTest, TestRandomFaceting, SpellCheckComponentTest, TestFastWriter, TestCloudManagedSchema, CachingDirectoryFactoryTest, ChangedSchemaMergeTest, TestExpandComponent, TestAnalyzeInfixSuggestions, TestPseudoReturnFields, TestDistribDocBasedVersion, AliasIntegrationTest, SystemInfoHandlerTest, TestBadConfig, TestFileDictionaryLookup, CollectionsAPIAsyncDistributedZkTest, SuggesterTest, NumericFieldsTest, TestSchemaVersionResource, AlternateDirectoryTest, DistributedQueryComponentCustomSortTest, CircularListTest, DateFieldTest, ReturnFieldsTest, TestValueSourceCache, TestSweetSpotSimilarityFactory, TestStandardQParsers, TestManagedResource, IndexSchemaTest, PeerSyncTest, DistanceFunctionTest, TestNRTOpen, TestComplexPhraseQParserPlugin, WordBreakSolrSpellCheckerTest, FileBasedSpellCheckerTest, UpdateParamsTest, TestDistributedSearch, TestUpdate, DeleteShardTest, TestShortCircuitedRequests, JsonLoaderTest, DirectSolrConnectionTest, PreAnalyzedUpdateProcessorTest, TestReversedWildcardFilterFactory, DistribDocExpirationUpdateProcessorTest, OpenExchangeRatesOrgProviderTest, ChaosMonkeyNothingIsSafeTest, TestSchemaResource, AbstractAnalyticsStatsTest, EchoParamsTest, TestInfoStreamLogging, TestSolrDeletionPolicy1, NotRequiredUniqueKeyTest, TermVectorComponentDistributedTest, SortByFunctionTest, ResourceLoaderTest, TestArbitraryIndexDir, CursorPagingTest, TestJmxIntegration, SimplePostToolTest, CurrencyFieldOpenExchangeTest, QueryEqualityTest, TestMergePolicyConfig, BinaryUpdateRequestHandlerTest, DirectUpdateHandlerTest, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test, CollectionsAPIDistributedZkTest]
   [junit4] Completed in 208.31s, 1 test, 1 error <<< FAILURES!

[...truncated 602 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:467: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:447: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:45: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/common-build.xml:496: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1275: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:907: There were test failures: 397 suites, 1674 tests, 1 error, 42 ignored (15 assumptions)

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



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

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

1 tests failed.
REGRESSION:  org.apache.solr.cloud.ShardSplitTest.testDistribSearch

Error Message:
Timeout occured while waiting response from server at: http://127.0.0.1:50406/saz/b

Stack Trace:
org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://127.0.0.1:50406/saz/b
	at __randomizedtesting.SeedInfo.seed([DA421A608BC8BBD9:5BA49478FC97DBE5]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:564)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:210)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:206)
	at org.apache.solr.cloud.ShardSplitTest.splitShard(ShardSplitTest.java:527)
	at org.apache.solr.cloud.ShardSplitTest.incompleteOrOverlappingCustomRangeTest(ShardSplitTest.java:135)
	at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:100)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:867)
	at sun.reflect.GeneratedMethodAccessor37.invoke(Unknown Source)
	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:1617)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
	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.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	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:359)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
	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 org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	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 org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	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:359)
	at java.lang.Thread.run(Thread.java:744)
Caused by: java.net.SocketTimeoutException: Read timed out
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.read(SocketInputStream.java:150)
	at java.net.SocketInputStream.read(SocketInputStream.java:121)
	at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:160)
	at org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:84)
	at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:273)
	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140)
	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)
	at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:260)
	at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:283)
	at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:251)
	at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:197)
	at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:271)
	at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:123)
	at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:682)
	at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:486)
	at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:863)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:57)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:452)
	... 44 more




Build Log:
[...truncated 10726 lines...]
   [junit4] Suite: org.apache.solr.cloud.ShardSplitTest
   [junit4]   2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-ShardSplitTest-1396590332280
   [junit4]   2> 1081946 T3851 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /saz/b
   [junit4]   2> 1081950 T3851 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> 1081952 T3851 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 1081953 T3852 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1082054 T3851 oasc.ZkTestServer.run start zk server on port:50396
   [junit4]   2> 1082055 T3851 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1082062 T3858 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@68e91bdb name:ZooKeeperConnection Watcher:127.0.0.1:50396 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1082063 T3851 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1082063 T3851 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1082073 T3851 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1082078 T3860 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@47d34bab name:ZooKeeperConnection Watcher:127.0.0.1:50396/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1082079 T3851 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1082079 T3851 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 1082088 T3851 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 1082096 T3851 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 1082102 T3851 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 1082110 T3851 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 1082111 T3851 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 1082122 T3851 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
   [junit4]   2> 1082123 T3851 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 1082134 T3851 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1082134 T3851 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1082142 T3851 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 1082143 T3851 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 1082149 T3851 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 1082150 T3851 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 1082156 T3851 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 1082156 T3851 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 1082162 T3851 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 1082162 T3851 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 1082168 T3851 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1082169 T3851 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1082176 T3851 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1082177 T3851 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1082182 T3851 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 1082183 T3851 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 1082189 T3851 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 1082190 T3851 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 1083717 T3851 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1083726 T3851 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50399
   [junit4]   2> 1083727 T3851 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1083728 T3851 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1083728 T3851 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-controljetty-1396590332534
   [junit4]   2> 1083729 T3851 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-controljetty-1396590332534/'
   [junit4]   2> 1083766 T3851 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-controljetty-1396590332534/solr.xml
   [junit4]   2> 1083781 T3851 oasc.CoreContainer.<init> New CoreContainer 581449247
   [junit4]   2> 1083781 T3851 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-controljetty-1396590332534/]
   [junit4]   2> 1083782 T3851 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1083782 T3851 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1083782 T3851 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1083783 T3851 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1083783 T3851 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1083783 T3851 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1083784 T3851 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1083784 T3851 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1083784 T3851 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1083785 T3851 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1083785 T3851 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1083785 T3851 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1083785 T3851 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50396/solr
   [junit4]   2> 1083786 T3851 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1083787 T3851 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1083792 T3871 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5677d032 name:ZooKeeperConnection Watcher:127.0.0.1:50396 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1083793 T3851 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1083799 T3851 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1083803 T3873 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a298e8e name:ZooKeeperConnection Watcher:127.0.0.1:50396/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1083804 T3851 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1083808 T3851 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1083819 T3851 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1083829 T3851 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 1083839 T3851 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 1083850 T3851 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 1083861 T3851 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1083866 T3851 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50399_saz%2Fb
   [junit4]   2> 1083868 T3851 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50399_saz%2Fb
   [junit4]   2> 1083877 T3851 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1083884 T3851 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1083896 T3851 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:50399_saz%2Fb
   [junit4]   2> 1083897 T3851 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1083903 T3851 oasc.Overseer.start Overseer (id=91526944017219587-127.0.0.1:50399_saz%2Fb-n_0000000000) starting
   [junit4]   2> 1083911 T3851 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1083938 T3875 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1083939 T3851 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1083941 T3875 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:50399_saz%2Fb
   [junit4]   2> 1083945 T3851 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1083949 T3851 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1083956 T3874 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1083960 T3876 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 1083960 T3876 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1083962 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1083962 T3876 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1083966 T3874 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1083968 T3874 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50399/saz/b",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50399_saz%2Fb",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1083968 T3874 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 1083968 T3874 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1083975 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1083977 T3873 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> 1084964 T3876 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1084964 T3876 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 1084966 T3876 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1084966 T3876 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 1084970 T3876 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1084970 T3876 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-controljetty-1396590332534/collection1/'
   [junit4]   2> 1084972 T3876 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-controljetty-1396590332534/collection1/lib/.svn/' to classloader
   [junit4]   2> 1084972 T3876 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-controljetty-1396590332534/collection1/lib/classes/' to classloader
   [junit4]   2> 1084972 T3876 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-controljetty-1396590332534/collection1/lib/README' to classloader
   [junit4]   2> 1085013 T3876 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1085025 T3876 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1085029 T3876 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1085035 T3876 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1085221 T3876 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1085223 T3876 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1085224 T3876 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1085230 T3876 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1085295 T3876 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 1085296 T3876 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1085296 T3876 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-controljetty-1396590332534/collection1/, dataDir=./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-1396590332286/control/data/
   [junit4]   2> 1085296 T3876 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@cf36413
   [junit4]   2> 1085297 T3876 oasc.CachingDirectoryFactory.get return new directory for ./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-1396590332286/control/data
   [junit4]   2> 1085297 T3876 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-1396590332286/control/data/index/
   [junit4]   2> 1085297 T3876 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-1396590332286/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1085298 T3876 oasc.CachingDirectoryFactory.get return new directory for ./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-1396590332286/control/data/index
   [junit4]   2> 1085298 T3876 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=40, maxMergeAtOnceExplicit=36, maxMergedSegmentMB=60.310546875, floorSegmentMB=0.3896484375, forceMergeDeletesPctAllowed=16.79376326725833, segmentsPerTier=12.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.20605092649545728
   [junit4]   2> 1085299 T3876 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@644417d lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6c9e20de),segFN=segments_1,generation=1}
   [junit4]   2> 1085299 T3876 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1085304 T3876 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1085304 T3876 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1085304 T3876 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1085305 T3876 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1085305 T3876 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1085306 T3876 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1085306 T3876 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1085306 T3876 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1085307 T3876 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1085307 T3876 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1085308 T3876 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1085308 T3876 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1085308 T3876 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1085308 T3876 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1085309 T3876 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1085309 T3876 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1085310 T3876 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 1085318 T3876 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1085323 T3876 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1085324 T3876 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1085324 T3876 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=34, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 1085325 T3876 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@644417d lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6c9e20de),segFN=segments_1,generation=1}
   [junit4]   2> 1085325 T3876 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1085325 T3876 oass.SolrIndexSearcher.<init> Opening Searcher@22c8b3cd[collection1] main
   [junit4]   2> 1085326 T3876 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 1085329 T3876 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1085330 T3876 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 1085331 T3876 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1085332 T3876 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 1085332 T3876 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1085335 T3876 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 1085335 T3876 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1085335 T3876 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 1085335 T3876 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 1085338 T3877 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@22c8b3cd[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1085340 T3876 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1085352 T3880 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50399/saz/b collection:control_collection shard:shard1
   [junit4]   2> 1085353 T3851 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1085353 T3851 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1085354 T3880 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 1085356 T3851 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1085363 T3882 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7e66873 name:ZooKeeperConnection Watcher:127.0.0.1:50396/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1085363 T3851 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1085368 T3851 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1085374 T3851 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 1085377 T3880 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1085383 T3880 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1085383 T3880 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C834 name=collection1 org.apache.solr.core.SolrCore@5b341268 url=http://127.0.0.1:50399/saz/b/collection1 node=127.0.0.1:50399_saz%2Fb C834_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:50399/saz/b, core=collection1, node_name=127.0.0.1:50399_saz%2Fb}
   [junit4]   2> 1085384 T3880 C834 P50399 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50399/saz/b/collection1/
   [junit4]   2> 1085384 T3880 C834 P50399 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1085384 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1085385 T3880 C834 P50399 oasc.SyncStrategy.syncToMe http://127.0.0.1:50399/saz/b/collection1/ has no replicas
   [junit4]   2> 1085386 T3880 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50399/saz/b/collection1/ shard1
   [junit4]   2> 1085387 T3880 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 1085392 T3874 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1085404 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1085410 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1085421 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1085529 T3882 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> 1085529 T3873 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> 1085566 T3880 oasc.ZkController.register We are http://127.0.0.1:50399/saz/b/collection1/ and leader is http://127.0.0.1:50399/saz/b/collection1/
   [junit4]   2> 1085566 T3880 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50399/saz/b
   [junit4]   2> 1085566 T3880 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1085566 T3880 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 1085567 T3880 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1085569 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1085569 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1085569 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1085572 T3880 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1085574 T3874 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1085577 T3874 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50399/saz/b",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50399_saz%2Fb",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 1085581 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1085686 T3882 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> 1085688 T3873 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> 1086897 T3851 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 1086898 T3851 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1086904 T3851 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50403
   [junit4]   2> 1086904 T3851 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1086906 T3851 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1086906 T3851 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-jetty1-1396590335710
   [junit4]   2> 1086906 T3851 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-jetty1-1396590335710/'
   [junit4]   2> 1086942 T3851 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-jetty1-1396590335710/solr.xml
   [junit4]   2> 1086960 T3851 oasc.CoreContainer.<init> New CoreContainer 152434813
   [junit4]   2> 1086960 T3851 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-jetty1-1396590335710/]
   [junit4]   2> 1086961 T3851 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1086962 T3851 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1086962 T3851 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1086962 T3851 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1086963 T3851 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1086963 T3851 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1086963 T3851 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1086963 T3851 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1086964 T3851 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1086964 T3851 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1086965 T3851 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1086965 T3851 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1086966 T3851 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50396/solr
   [junit4]   2> 1086966 T3851 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1086968 T3851 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1086974 T3893 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2aed9dd7 name:ZooKeeperConnection Watcher:127.0.0.1:50396 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1086975 T3851 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1086982 T3851 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1086987 T3895 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5930fa82 name:ZooKeeperConnection Watcher:127.0.0.1:50396/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1086987 T3851 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1087006 T3851 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1088014 T3851 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50403_saz%2Fb
   [junit4]   2> 1088017 T3851 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50403_saz%2Fb
   [junit4]   2> 1088023 T3873 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1088024 T3882 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1088024 T3895 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1088038 T3896 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 1088039 T3896 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1088041 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1088041 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1088041 T3896 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1088042 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1088045 T3874 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1088046 T3874 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50403/saz/b",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50403_saz%2Fb",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1088047 T3874 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 1088047 T3874 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 1088053 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1088055 T3873 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> 1088055 T3882 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> 1088055 T3895 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> 1089044 T3896 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1089044 T3896 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1089046 T3896 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1089046 T3896 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1089048 T3896 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1089049 T3896 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-jetty1-1396590335710/collection1/'
   [junit4]   2> 1089050 T3896 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-jetty1-1396590335710/collection1/lib/.svn/' to classloader
   [junit4]   2> 1089050 T3896 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-jetty1-1396590335710/collection1/lib/classes/' to classloader
   [junit4]   2> 1089051 T3896 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-jetty1-1396590335710/collection1/lib/README' to classloader
   [junit4]   2> 1089091 T3896 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1089111 T3896 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1089115 T3896 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1089119 T3896 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1089278 T3896 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1089280 T3896 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1089281 T3896 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1089286 T3896 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1089337 T3896 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 1089337 T3896 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1089337 T3896 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-jetty1-1396590335710/collection1/, dataDir=./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-1396590332286/jetty1/
   [junit4]   2> 1089338 T3896 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@cf36413
   [junit4]   2> 1089338 T3896 oasc.CachingDirectoryFactory.get return new directory for ./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-1396590332286/jetty1
   [junit4]   2> 1089339 T3896 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-1396590332286/jetty1/index/
   [junit4]   2> 1089339 T3896 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-1396590332286/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 1089339 T3896 oasc.CachingDirectoryFactory.get return new directory for ./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-1396590332286/jetty1/index
   [junit4]   2> 1089340 T3896 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=40, maxMergeAtOnceExplicit=36, maxMergedSegmentMB=60.310546875, floorSegmentMB=0.3896484375, forceMergeDeletesPctAllowed=16.79376326725833, segmentsPerTier=12.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.20605092649545728
   [junit4]   2> 1089341 T3896 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@58124991 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5178d307),segFN=segments_1,generation=1}
   [junit4]   2> 1089341 T3896 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1089347 T3896 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1089348 T3896 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1089348 T3896 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1089348 T3896 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1089348 T3896 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1089348 T3896 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1089349 T3896 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1089349 T3896 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1089349 T3896 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1089350 T3896 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1089350 T3896 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1089350 T3896 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1089351 T3896 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1089351 T3896 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1089351 T3896 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1089352 T3896 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1089352 T3896 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 1089359 T3896 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1089363 T3896 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1089363 T3896 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1089364 T3896 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=34, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 1089365 T3896 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@58124991 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5178d307),segFN=segments_1,generation=1}
   [junit4]   2> 1089365 T3896 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1089365 T3896 oass.SolrIndexSearcher.<init> Opening Searcher@124abbe2[collection1] main
   [junit4]   2> 1089366 T3896 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1089368 T3896 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1089368 T3896 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 1089369 T3896 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1089369 T3896 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 1089370 T3896 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1089371 T3896 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 1089371 T3896 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1089372 T3896 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 1089372 T3896 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 1089375 T3897 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@124abbe2[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1089378 T3896 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1089380 T3900 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50403/saz/b collection:collection1 shard:shard2
   [junit4]   2> 1089382 T3851 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1089382 T3851 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1089383 T3900 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 1089399 T3900 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 1089402 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1089406 T3874 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1089407 T3900 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1089407 T3900 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C835 name=collection1 org.apache.solr.core.SolrCore@7b31ba10 url=http://127.0.0.1:50403/saz/b/collection1 node=127.0.0.1:50403_saz%2Fb C835_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:50403/saz/b, core=collection1, node_name=127.0.0.1:50403_saz%2Fb}
   [junit4]   2> 1089407 T3900 C835 P50403 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50403/saz/b/collection1/
   [junit4]   2> 1089408 T3900 C835 P50403 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1089408 T3900 C835 P50403 oasc.SyncStrategy.syncToMe http://127.0.0.1:50403/saz/b/collection1/ has no replicas
   [junit4]   2> 1089408 T3900 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50403/saz/b/collection1/ shard2
   [junit4]   2> 1089408 T3900 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 1089418 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1089427 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1089433 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1089538 T3895 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> 1089539 T3873 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> 1089541 T3882 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> 1089585 T3900 oasc.ZkController.register We are http://127.0.0.1:50403/saz/b/collection1/ and leader is http://127.0.0.1:50403/saz/b/collection1/
   [junit4]   2> 1089586 T3900 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50403/saz/b
   [junit4]   2> 1089586 T3900 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1089586 T3900 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 1089586 T3900 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1089588 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1089588 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1089589 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1089591 T3874 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1089592 T3874 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50403/saz/b",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50403_saz%2Fb",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 1089593 T3900 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1089599 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1089704 T3895 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> 1089705 T3873 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> 1089705 T3882 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> 1090931 T3851 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 1090931 T3851 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1090949 T3851 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50406
   [junit4]   2> 1090951 T3851 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1090952 T3851 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1090952 T3851 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-jetty2-1396590339718
   [junit4]   2> 1090952 T3851 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-jetty2-1396590339718/'
   [junit4]   2> 1090987 T3851 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-jetty2-1396590339718/solr.xml
   [junit4]   2> 1091004 T3851 oasc.CoreContainer.<init> New CoreContainer 13230901
   [junit4]   2> 1091004 T3851 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-jetty2-1396590339718/]
   [junit4]   2> 1091005 T3851 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1091005 T3851 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1091006 T3851 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1091006 T3851 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1091007 T3851 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1091007 T3851 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1091007 T3851 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1091008 T3851 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1091008 T3851 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1091008 T3851 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1091009 T3851 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1091009 T3851 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1091010 T3851 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50396/solr
   [junit4]   2> 1091010 T3851 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1091011 T3851 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1091016 T3911 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3f708f3a name:ZooKeeperConnection Watcher:127.0.0.1:50396 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1091017 T3851 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1091024 T3851 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1091028 T3913 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c5f98dd name:ZooKeeperConnection Watcher:127.0.0.1:50396/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1091029 T3851 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1091047 T3851 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1092058 T3851 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50406_saz%2Fb
   [junit4]   2> 1092063 T3851 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50406_saz%2Fb
   [junit4]   2> 1092079 T3882 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1092080 T3895 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1092079 T3873 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1092081 T3913 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1092105 T3914 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 1092106 T3914 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1092110 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1092110 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1092110 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1092110 T3914 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1092119 T3874 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1092123 T3874 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50406/saz/b",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50406_saz%2Fb",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1092123 T3874 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 1092124 T3874 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1092139 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1092143 T3895 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> 1092143 T3882 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> 1092143 T3873 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> 1092143 T3913 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> 1093113 T3914 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1093113 T3914 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1093115 T3914 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1093115 T3914 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1093118 T3914 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1093118 T3914 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-jetty2-1396590339718/collection1/'
   [junit4]   2> 1093120 T3914 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-jetty2-1396590339718/collection1/lib/.svn/' to classloader
   [junit4]   2> 1093120 T3914 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-jetty2-1396590339718/collection1/lib/classes/' to classloader
   [junit4]   2> 1093121 T3914 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-jetty2-1396590339718/collection1/lib/README' to classloader
   [junit4]   2> 1093160 T3914 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 1093172 T3914 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1093175 T3914 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1093179 T3914 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1093304 T3914 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1093305 T3914 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1093306 T3914 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1093312 T3914 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1093363 T3914 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 1093364 T3914 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1093364 T3914 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-jetty2-1396590339718/collection1/, dataDir=./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-1396590332286/jetty2/
   [junit4]   2> 1093364 T3914 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@cf36413
   [junit4]   2> 1093365 T3914 oasc.CachingDirectoryFactory.get return new directory for ./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-1396590332286/jetty2
   [junit4]   2> 1093365 T3914 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-1396590332286/jetty2/index/
   [junit4]   2> 1093365 T3914 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-1396590332286/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 1093366 T3914 oasc.CachingDirectoryFactory.get return new directory for ./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-1396590332286/jetty2/index
   [junit4]   2> 1093366 T3914 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=40, maxMergeAtOnceExplicit=36, maxMergedSegmentMB=60.310546875, floorSegmentMB=0.3896484375, forceMergeDeletesPctAllowed=16.79376326725833, segmentsPerTier=12.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.20605092649545728
   [junit4]   2> 1093366 T3914 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1ba55d62 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@18bbd7e2),segFN=segments_1,generation=1}
   [junit4]   2> 1093367 T3914 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1093371 T3914 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1093372 T3914 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1093372 T3914 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1093372 T3914 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1093372 T3914 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1093372 T3914 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1093373 T3914 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1093373 T3914 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1093374 T3914 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1093374 T3914 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1093375 T3914 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1093375 T3914 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1093375 T3914 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1093376 T3914 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1093376 T3914 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1093377 T3914 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1093377 T3914 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 1093383 T3914 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1093386 T3914 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1093387 T3914 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1093387 T3914 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=34, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 1093388 T3914 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1ba55d62 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@18bbd7e2),segFN=segments_1,generation=1}
   [junit4]   2> 1093388 T3914 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1093388 T3914 oass.SolrIndexSearcher.<init> Opening Searcher@3ffc221a[collection1] main
   [junit4]   2> 1093389 T3914 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1093391 T3914 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1093391 T3914 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 1093392 T3914 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1093393 T3914 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 1093393 T3914 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1093394 T3914 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 1093394 T3914 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1093395 T3914 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 1093395 T3914 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 1093400 T3915 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3ffc221a[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1093402 T3914 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1093403 T3918 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50406/saz/b collection:collection1 shard:shard1
   [junit4]   2> 1093404 T3851 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1093405 T3851 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1093417 T3918 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1093432 T3918 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1093436 T3918 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1093436 T3918 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C836 name=collection1 org.apache.solr.core.SolrCore@635ad7fc url=http://127.0.0.1:50406/saz/b/collection1 node=127.0.0.1:50406_saz%2Fb C836_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:50406/saz/b, core=collection1, node_name=127.0.0.1:50406_saz%2Fb}
   [junit4]   2> 1093436 T3918 C836 P50406 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50406/saz/b/collection1/
   [junit4]   2> 1093436 T3918 C836 P50406 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1093437 T3918 C836 P50406 oasc.SyncStrategy.syncToMe http://127.0.0.1:50406/saz/b/collection1/ has no replicas
   [junit4]   2> 1093437 T3918 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50406/saz/b/collection1/ shard1
   [junit4]   2> 1093437 T3918 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1093438 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1093442 T3874 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1093448 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1093456 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1093464 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1093567 T3882 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> 1093568 T3873 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> 1093569 T3913 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> 1093571 T3895 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> 1093608 T3918 oasc.ZkController.register We are http://127.0.0.1:50406/saz/b/collection1/ and leader is http://127.0.0.1:50406/saz/b/collection1/
   [junit4]   2> 1093609 T3918 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50406/saz/b
   [junit4]   2> 1093609 T3918 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1093609 T3918 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 1093610 T3918 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1093612 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1093612 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1093612 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1093614 T3874 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1093615 T3874 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50406/saz/b",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50406_saz%2Fb",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 1093617 T3918 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1093622 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1093728 T3882 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> 1093729 T3913 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> 1093729 T3895 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> 1093731 T3873 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> 1094969 T3851 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
   [junit4]   2> 1094970 T3851 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1094976 T3851 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50409
   [junit4]   2> 1094976 T3851 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1094978 T3851 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1094978 T3851 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-jetty3-1396590343740
   [junit4]   2> 1094978 T3851 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-jetty3-1396590343740/'
   [junit4]   2> 1095014 T3851 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-jetty3-1396590343740/solr.xml
   [junit4]   2> 1095044 T3851 oasc.CoreContainer.<init> New CoreContainer 2073887305
   [junit4]   2> 1095045 T3851 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solrtest-ShardSplitTest-1396590332280/org.apache.solr.cloud.ShardSplitTest-jetty3-1396590343740/]
   [junit4]   2> 1095045 T3851 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1095045 T3851 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1095046 T3851 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1095046 T3851 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1095046 T3851 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1095046 T3851 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1095047 T3851 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1095047 T3851 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1095047 T3851 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1095048 T3851 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1095048 T3851 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1095048 T3851 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1095049 T3851 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50396/solr
   [junit4]   2> 1095050 T3851 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1095051 T3851 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1095056 T3929 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6943ca86 name:ZooKeeperConnection Watcher:127.0.0.1:50396 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1095058 T3851 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1095064 T3851 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1095067 T3931 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7137376 name:ZooKeeperConnection Watcher:127.0.0.1:50396/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1095068 T3851 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1095087 T3851 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1096095 T3851 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50409_saz%2Fb
   [junit4]   2> 1096098 T3851 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50409_saz%2Fb
   [junit4]   2> 1096104 T3913 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1096105 T3931 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1096105 T3895 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1096105 T3882 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1096106 T3873 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1096117 T3932 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 1096117 T3932 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1096119 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1096119 T3873 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1096120 T3873 oasc.DistributedQue

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

onContext.runLeaderProcess(ElectionContext.java:291)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
   [junit4]   2> 		at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 		at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> 	Caused by: org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections
   [junit4]   2> 		at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 		at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 		at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1045)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:209)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient$3.execute(SolrZkClient.java:206)
   [junit4]   2> 		at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:206)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:417)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:386)
   [junit4]   2> 		at org.apache.solr.common.cloud.SolrZkClient.makePath(SolrZkClient.java:373)
   [junit4]   2> 		at org.apache.solr.cloud.ShardLeaderElectionContextBase$1.execute(ElectionContext.java:128)
   [junit4]   2> 		at org.apache.solr.common.util.RetryUtil.retryOnThrowable(RetryUtil.java:31)
   [junit4]   2> 		at org.apache.solr.cloud.ShardLeaderElectionContextBase.runLeaderProcess(ElectionContext.java:123)
   [junit4]   2> 		... 7 more
   [junit4]   2> 	
   [junit4]   2> 1410691 T3951 oasc.ElectionContext.cancelElection canceling election /collections/collection1/leader_elect/shard1/election/91526944017219596-core_node4-n_0000000001
   [junit4]   2> 1410691 T3951 oasc.LeaderElector$ElectionWatcher.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election/91526944017219596-core_node4-n_0000000001
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:177)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:174)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:174)
   [junit4]   2> 	at org.apache.solr.cloud.ElectionContext.cancelElection(ElectionContext.java:72)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:310)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:142)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:110)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> 
   [junit4]   2> 1410691 T3951 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 1410691 T3951 oasc.LeaderElector$ElectionWatcher.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> 
   [junit4]   2> NOTE: test params are: codec=Lucene42, sim=DefaultSimilarity, locale=is, timezone=SystemV/PST8PDT
   [junit4]   2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.8.0 (64-bit)/cpus=2,threads=1,free=179384112,total=327680000
   [junit4]   2> NOTE: All tests run in this JVM: [TestNumberUtils, SolrInfoMBeanTest, TestNoOpRegenerator, TestSolrDeletionPolicy2, TestCharFilters, OpenExchangeRatesOrgProviderTest, TestRestManager, EchoParamsTest, SSLMigrationTest, OutputWriterTest, ChangedSchemaMergeTest, DistributedQueryElevationComponentTest, SuggesterTSTTest, SortByFunctionTest, TestClassNameShortening, TestManagedResource, TestCloudManagedSchema, TestPostingsSolrHighlighter, TestAddFieldRealTimeGet, TestManagedSchemaFieldResource, DateFieldTest, DeleteReplicaTest, DistribDocExpirationUpdateProcessorTest, ShardRoutingTest, SearchHandlerTest, BlockCacheTest, TestRangeQuery, FieldFacetTest, HighlighterTest, SyncSliceTest, TestOverriddenPrefixQueryForCustomFieldType, TestCollationField, JsonLoaderTest, LoggingHandlerTest, TestRandomMergePolicy, LeaderElectionIntegrationTest, SynonymTokenizerTest, TestDistribDocBasedVersion, HdfsLockFactoryTest, DirectSolrConnectionTest, BlockDirectoryTest, FieldFacetExtrasTest, FileBasedSpellCheckerTest, CoreMergeIndexesAdminHandlerTest, QueryEqualityTest, CopyFieldTest, TestWordDelimiterFilterFactory, PluginInfoTest, TestFastLRUCache, TestReload, QueryElevationComponentTest, TestCodecSupport, UniqFieldsUpdateProcessorFactoryTest, StatsComponentTest, RAMDirectoryFactoryTest, TestSolrQueryParser, AssignTest, TestShardHandlerFactory, TestCSVResponseWriter, SuggesterFSTTest, TestSolrXMLSerializer, TestRemoteStreaming, TestZkChroot, SliceStateUpdateTest, HardAutoCommitTest, MultiTermTest, TestXIncludeConfig, AddSchemaFieldsUpdateProcessorFactoryTest, TestDefaultSearchFieldResource, TestDocumentBuilder, TestQueryUtils, TestSort, DeleteInactiveReplicaTest, BadIndexSchemaTest, StressHdfsTest, TestManagedResourceStorage, ConnectionManagerTest, TestMaxScoreQueryParser, DebugComponentTest, AlternateDirectoryTest, TestStressRecovery, DeleteShardTest, ZkNodePropsTest, QueryResultKeyTest, AbstractAnalyticsFacetTest, TestLMJelinekMercerSimilarityFactory, SolrCmdDistributorTest, TestBM25SimilarityFactory, ClusterStateTest, TestManagedStopFilterFactory, ConvertedLegacyTest, TestBinaryField, RequiredFieldsTest, AbstractAnalyticsStatsTest, TestQuerySenderNoQuery, DistributedExpandComponentTest, SolrRequestParserTest, ScriptEngineTest, TestPartialUpdateDeduplication, TestReloadAndDeleteDocs, SimpleFacetsTest, TestCollationFieldDocValues, TestSchemaVersionResource, TestStandardQParsers, DocumentAnalysisRequestHandlerTest, TestReversedWildcardFilterFactory, BasicDistributedZkTest, TestFieldSortValues, FullSolrCloudDistribCmdsTest, TestNRTOpen, OverseerStatusTest, ShardRoutingCustomTest, HdfsUnloadDistributedZkTest, FunctionTest, TestDFRSimilarityFactory, SuggestComponentTest, CachingDirectoryFactoryTest, BasicFunctionalityTest, CustomCollectionTest, TestPerFieldSimilarity, ShardSplitTest]
   [junit4] Completed in 332.06s, 1 test, 1 error <<< FAILURES!

[...truncated 855 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:467: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:447: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:45: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/common-build.xml:496: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1275: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:907: There were test failures: 397 suites, 1674 tests, 1 error, 42 ignored (15 assumptions)

Total time: 96 minutes 1 second
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure