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/05/22 13:42:52 UTC

[JENKINS] Lucene-Solr-4.x-Windows (64bit/jdk1.8.0_20-ea-b11) - Build # 3970 - Still Failing!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/3970/
Java: 64bit/jdk1.8.0_20-ea-b11 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC

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

Error Message:
Cannot talk to ZooKeeper - Updates are disabled.

Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Cannot talk to ZooKeeper - Updates are disabled.
	at __randomizedtesting.SeedInfo.seed([24A9853F6A21A3AE:A54F0B271D7EC392]: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.AbstractUpdateRequest.process(AbstractUpdateRequest.java:124)
	at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:168)
	at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:146)
	at org.apache.solr.cloud.BasicDistributedZkTest.testUpdateProcessorsRunOnlyOnce(BasicDistributedZkTest.java:667)
	at org.apache.solr.cloud.BasicDistributedZkTest.doTest(BasicDistributedZkTest.java:376)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:865)
	at sun.reflect.GeneratedMethodAccessor56.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:1618)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
	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:65)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
	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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
	at java.lang.Thread.run(Thread.java:745)




Build Log:
[...truncated 11224 lines...]
   [junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest
   [junit4]   2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\init-core-data-001
   [junit4]   2> 2425089 T8100 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /x/m
   [junit4]   2> 2425092 T8100 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> 2425094 T8100 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 2425094 T8101 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 2425174 T8100 oasc.ZkTestServer.run start zk server on port:57803
   [junit4]   2> 2425177 T8100 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2425183 T8107 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@32c11f6a name:ZooKeeperConnection Watcher:127.0.0.1:57803 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2425184 T8100 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2425184 T8100 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 2425189 T8102 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x14623a0653a0000, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 2425191 T8100 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2425194 T8109 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5ef4509a name:ZooKeeperConnection Watcher:127.0.0.1:57803/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2425195 T8100 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2425195 T8100 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 2425199 T8100 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 2425201 T8100 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 2425204 T8100 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 2425207 T8100 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 2425209 T8100 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 2425214 T8100 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 2425214 T8100 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 2425220 T8100 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 2425221 T8100 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 2425224 T8100 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 2425224 T8100 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 2425228 T8100 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 2425228 T8100 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 2425231 T8100 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 2425231 T8100 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 2425235 T8100 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 2425235 T8100 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 2425239 T8100 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 2425239 T8100 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 2425243 T8100 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 2425243 T8100 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 2425247 T8100 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 2425247 T8100 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 2425251 T8100 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 2425251 T8100 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 2426919 T8100 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 2426932 T8100 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57810
   [junit4]   2> 2426932 T8100 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 2426932 T8100 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2426932 T8100 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-002
   [junit4]   2> 2426932 T8100 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-002\'
   [junit4]   2> 2426965 T8100 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-002\solr.xml
   [junit4]   2> 2426978 T8100 oasc.CoreContainer.<init> New CoreContainer 1588161802
   [junit4]   2> 2426978 T8100 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-002\]
   [junit4]   2> 2426979 T8100 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 2426979 T8100 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 2426980 T8100 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 2426980 T8100 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 2426980 T8100 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 2426980 T8100 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 2426980 T8100 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 2426980 T8100 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 2426981 T8100 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 2426981 T8100 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 2426982 T8100 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 2426982 T8100 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 2426982 T8100 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57803/solr
   [junit4]   2> 2426983 T8100 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2426985 T8100 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2427008 T8120 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a97443e name:ZooKeeperConnection Watcher:127.0.0.1:57803 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2427009 T8100 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2427022 T8100 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2427026 T8122 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@de9c0ef name:ZooKeeperConnection Watcher:127.0.0.1:57803/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2427026 T8100 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2427029 T8100 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 2427035 T8100 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 2427040 T8100 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 2427044 T8100 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 2427049 T8100 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 2427055 T8100 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 2427058 T8100 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57810_x%2Fm
   [junit4]   2> 2427060 T8100 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57810_x%2Fm
   [junit4]   2> 2427064 T8100 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 2427068 T8100 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 2427074 T8100 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:57810_x%2Fm
   [junit4]   2> 2427075 T8100 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 2427081 T8100 oasc.Overseer.start Overseer (id=91800014207713283-127.0.0.1:57810_x%2Fm-n_0000000000) starting
   [junit4]   2> 2427084 T8100 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 2427107 T8124 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 2427108 T8100 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 2427112 T8100 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 2427114 T8100 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2427118 T8123 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 2427122 T8125 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 2427122 T8125 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2427124 T8125 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 2427124 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2427125 T8123 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2427126 T8123 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:57810/x/m",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:57810_x%2Fm",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 2427126 T8123 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 2427126 T8123 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 2427130 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2427131 T8122 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> 2428001 T8125 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 2428001 T8125 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 2428003 T8125 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 2428004 T8125 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 2428005 T8125 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 2428005 T8125 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-002\collection1\'
   [junit4]   2> 2428008 T8125 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001/tempDir-002/collection1/lib/.svn/' to classloader
   [junit4]   2> 2428008 T8125 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001/tempDir-002/collection1/lib/classes/' to classloader
   [junit4]   2> 2428010 T8125 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001/tempDir-002/collection1/lib/README' to classloader
   [junit4]   2> 2428064 T8125 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
   [junit4]   2> 2428078 T8125 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 2428082 T8125 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 2428087 T8125 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 2428241 T8125 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 2428241 T8125 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 2428243 T8125 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 2428249 T8125 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2428249 T8125 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2428269 T8125 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2428273 T8125 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2428276 T8125 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2428278 T8125 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2428278 T8125 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2428278 T8125 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2428280 T8125 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2428280 T8125 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2428280 T8125 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 2428281 T8125 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 2428282 T8125 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-002\collection1\, dataDir=.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-001/control/data\
   [junit4]   2> 2428282 T8125 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@ba91290
   [junit4]   2> 2428283 T8125 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-001/control/data\
   [junit4]   2> 2428283 T8125 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-001/control/data\index/
   [junit4]   2> 2428283 T8125 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-001\control\data\index' doesn't exist. Creating new index...
   [junit4]   2> 2428284 T8125 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-001/control/data\index
   [junit4]   2> 2428284 T8125 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=42, maxMergeAtOnceExplicit=33, maxMergedSegmentMB=29.052734375, floorSegmentMB=1.40234375, forceMergeDeletesPctAllowed=8.18380897088708, segmentsPerTier=18.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.17563226751976968
   [junit4]   2> 2428285 T8125 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@2f300f8f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@47d4b88c),segFN=segments_1,generation=1}
   [junit4]   2> 2428285 T8125 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2428287 T8125 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 2428287 T8125 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 2428288 T8125 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 2428288 T8125 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2428288 T8125 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2428288 T8125 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 2428289 T8125 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2428289 T8125 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2428289 T8125 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 2428290 T8125 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 2428290 T8125 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 2428290 T8125 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 2428290 T8125 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 2428291 T8125 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 2428291 T8125 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 2428291 T8125 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 2428295 T8125 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2428301 T8125 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 2428301 T8125 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 2428302 T8125 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=22, maxMergeAtOnceExplicit=35, maxMergedSegmentMB=96.375, floorSegmentMB=2.078125, forceMergeDeletesPctAllowed=23.681496182561734, segmentsPerTier=21.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7689713790832439
   [junit4]   2> 2428302 T8125 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@2f300f8f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@47d4b88c),segFN=segments_1,generation=1}
   [junit4]   2> 2428302 T8125 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2428303 T8125 oass.SolrIndexSearcher.<init> Opening Searcher@534b4005[collection1] main
   [junit4]   2> 2428303 T8125 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 2428304 T8125 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 2428304 T8125 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 2428305 T8125 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 2428305 T8125 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 2428305 T8125 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2428307 T8125 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 2428307 T8125 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2428307 T8125 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 2428307 T8125 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 2428309 T8126 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@534b4005[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 2428310 T8125 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 2428312 T8129 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57810/x/m collection:control_collection shard:shard1
   [junit4]   2> 2428313 T8100 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 2428313 T8100 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 2428315 T8129 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 2428317 T8100 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2428321 T8131 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@83bf972 name:ZooKeeperConnection Watcher:127.0.0.1:57803/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2428321 T8100 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2428323 T8100 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2428331 T8100 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 2428333 T8129 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 2428338 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2428340 T8129 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 2428340 T8129 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C4852 name=collection1 org.apache.solr.core.SolrCore@4b59b784 url=http://127.0.0.1:57810/x/m/collection1 node=127.0.0.1:57810_x%2Fm C4852_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:57810/x/m, core=collection1, node_name=127.0.0.1:57810_x%2Fm}
   [junit4]   2> 2428340 T8129 C4852 P57810 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57810/x/m/collection1/
   [junit4]   2> 2428340 T8129 C4852 P57810 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 2428340 T8129 C4852 P57810 oasc.SyncStrategy.syncToMe http://127.0.0.1:57810/x/m/collection1/ has no replicas
   [junit4]   2> 2428340 T8129 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57810/x/m/collection1/ shard1
   [junit4]   2> 2428342 T8129 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 2428345 T8123 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2428355 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2428361 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2428389 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2428483 T8131 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> 2428483 T8122 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> 2428511 T8129 oasc.ZkController.register We are http://127.0.0.1:57810/x/m/collection1/ and leader is http://127.0.0.1:57810/x/m/collection1/
   [junit4]   2> 2428511 T8129 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57810/x/m
   [junit4]   2> 2428511 T8129 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 2428511 T8129 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 2428511 T8129 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2428519 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2428519 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2428519 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2428520 T8129 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2428523 T8123 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2428525 T8123 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:57810/x/m",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:57810_x%2Fm",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 2428529 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2428621 T8131 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> 2428621 T8122 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> 2430189 T8100 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 2430189 T8100 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 2430192 T8100 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57822
   [junit4]   2> 2430192 T8100 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 2430193 T8100 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2430193 T8100 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-003
   [junit4]   2> 2430194 T8100 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-003\'
   [junit4]   2> 2430232 T8100 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-003\solr.xml
   [junit4]   2> 2430242 T8100 oasc.CoreContainer.<init> New CoreContainer 1004859174
   [junit4]   2> 2430242 T8100 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-003\]
   [junit4]   2> 2430243 T8100 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 2430243 T8100 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 2430243 T8100 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 2430243 T8100 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 2430243 T8100 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 2430243 T8100 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 2430245 T8100 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 2430245 T8100 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 2430245 T8100 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 2430245 T8100 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 2430245 T8100 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 2430245 T8100 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 2430247 T8100 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57803/solr
   [junit4]   2> 2430247 T8100 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2430249 T8100 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2430263 T8142 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7d618cbb name:ZooKeeperConnection Watcher:127.0.0.1:57803 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2430264 T8100 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2430275 T8102 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x14623a0653a0005, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 2430277 T8100 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2430280 T8144 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5a294302 name:ZooKeeperConnection Watcher:127.0.0.1:57803/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2430280 T8100 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2430291 T8100 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2431173 T8100 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57822_x%2Fm
   [junit4]   2> 2431175 T8100 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57822_x%2Fm
   [junit4]   2> 2431181 T8122 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 2431183 T8131 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 2431183 T8144 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 2431192 T8145 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 2431192 T8145 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2431194 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2431194 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2431194 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2431194 T8145 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 2431196 T8123 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2431196 T8123 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:57822/x/m",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:57822_x%2Fm",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 2431197 T8123 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 2431197 T8123 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 2431201 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2431202 T8131 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> 2431202 T8122 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> 2431202 T8144 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> 2432072 T8145 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 2432072 T8145 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 2432074 T8145 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 2432074 T8145 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 2432077 T8145 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 2432077 T8145 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-003\collection1\'
   [junit4]   2> 2432082 T8145 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001/tempDir-003/collection1/lib/.svn/' to classloader
   [junit4]   2> 2432084 T8145 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001/tempDir-003/collection1/lib/classes/' to classloader
   [junit4]   2> 2432086 T8145 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001/tempDir-003/collection1/lib/README' to classloader
   [junit4]   2> 2432141 T8145 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
   [junit4]   2> 2432149 T8145 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 2432153 T8145 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 2432160 T8145 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 2432335 T8145 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 2432335 T8145 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 2432338 T8145 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 2432356 T8145 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2432356 T8145 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2432378 T8145 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2432383 T8145 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2432388 T8145 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2432391 T8145 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2432391 T8145 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2432391 T8145 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2432393 T8145 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2432393 T8145 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2432393 T8145 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 2432393 T8145 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 2432400 T8145 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-003\collection1\, dataDir=.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-001/jetty1\
   [junit4]   2> 2432400 T8145 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@ba91290
   [junit4]   2> 2432401 T8145 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-001/jetty1\
   [junit4]   2> 2432401 T8145 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-001/jetty1\index/
   [junit4]   2> 2432401 T8145 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-001\jetty1\index' doesn't exist. Creating new index...
   [junit4]   2> 2432402 T8145 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-001/jetty1\index
   [junit4]   2> 2432406 T8145 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=42, maxMergeAtOnceExplicit=33, maxMergedSegmentMB=29.052734375, floorSegmentMB=1.40234375, forceMergeDeletesPctAllowed=8.18380897088708, segmentsPerTier=18.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.17563226751976968
   [junit4]   2> 2432407 T8145 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1d735cc5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5b6564fd),segFN=segments_1,generation=1}
   [junit4]   2> 2432407 T8145 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2432407 T8145 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 2432407 T8145 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 2432407 T8145 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 2432407 T8145 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2432408 T8145 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2432408 T8145 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 2432409 T8145 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2432410 T8145 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2432410 T8145 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 2432411 T8145 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 2432411 T8145 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 2432411 T8145 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 2432411 T8145 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 2432412 T8145 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 2432412 T8145 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 2432413 T8145 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 2432419 T8145 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2432426 T8145 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 2432426 T8145 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 2432427 T8145 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=22, maxMergeAtOnceExplicit=35, maxMergedSegmentMB=96.375, floorSegmentMB=2.078125, forceMergeDeletesPctAllowed=23.681496182561734, segmentsPerTier=21.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7689713790832439
   [junit4]   2> 2432428 T8145 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1d735cc5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5b6564fd),segFN=segments_1,generation=1}
   [junit4]   2> 2432428 T8145 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2432429 T8145 oass.SolrIndexSearcher.<init> Opening Searcher@72c67d71[collection1] main
   [junit4]   2> 2432429 T8145 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 2432430 T8145 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 2432431 T8145 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 2432432 T8145 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 2432432 T8145 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 2432432 T8145 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2432433 T8145 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 2432433 T8145 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2432433 T8145 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 2432433 T8145 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 2432440 T8146 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@72c67d71[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 2432441 T8145 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 2432444 T8100 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 2432444 T8100 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 2432449 T8149 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57822/x/m collection:collection1 shard:shard2
   [junit4]   2> 2432460 T8149 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 2432489 T8149 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 2432492 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2432494 T8149 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 2432494 T8149 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C4853 name=collection1 org.apache.solr.core.SolrCore@6e2b386 url=http://127.0.0.1:57822/x/m/collection1 node=127.0.0.1:57822_x%2Fm C4853_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:57822/x/m, core=collection1, node_name=127.0.0.1:57822_x%2Fm}
   [junit4]   2> 2432494 T8149 C4853 P57822 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57822/x/m/collection1/
   [junit4]   2> 2432494 T8149 C4853 P57822 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 2432494 T8149 C4853 P57822 oasc.SyncStrategy.syncToMe http://127.0.0.1:57822/x/m/collection1/ has no replicas
   [junit4]   2> 2432494 T8149 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57822/x/m/collection1/ shard2
   [junit4]   2> 2432495 T8149 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 2432496 T8123 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2432503 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2432505 T8144 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> 2432506 T8131 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> 2432507 T8122 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> 2432513 T8123 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2432518 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2432615 T8144 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> 2432621 T8131 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> 2432621 T8122 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> 2432646 T8149 oasc.ZkController.register We are http://127.0.0.1:57822/x/m/collection1/ and leader is http://127.0.0.1:57822/x/m/collection1/
   [junit4]   2> 2432646 T8149 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57822/x/m
   [junit4]   2> 2432646 T8149 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 2432646 T8149 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 2432646 T8149 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2432655 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2432656 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2432656 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2432658 T8149 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2432663 T8123 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2432664 T8123 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:57822/x/m",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:57822_x%2Fm",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 2432674 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2432766 T8131 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> 2432766 T8122 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> 2432767 T8144 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> 2434339 T8100 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 2434339 T8100 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 2434343 T8100 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57831
   [junit4]   2> 2434344 T8100 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 2434344 T8100 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2434344 T8100 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-004
   [junit4]   2> 2434344 T8100 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-004\'
   [junit4]   2> 2434375 T8100 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-004\solr.xml
   [junit4]   2> 2434397 T8100 oasc.CoreContainer.<init> New CoreContainer 952327116
   [junit4]   2> 2434398 T8100 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-004\]
   [junit4]   2> 2434399 T8100 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 2434399 T8100 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 2434399 T8100 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 2434399 T8100 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 2434399 T8100 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 2434399 T8100 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 2434400 T8100 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 2434400 T8100 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 2434400 T8100 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 2434401 T8100 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 2434401 T8100 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 2434402 T8100 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 2434402 T8100 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57803/solr
   [junit4]   2> 2434403 T8100 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2434404 T8100 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2434418 T8160 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3eb9b67c name:ZooKeeperConnection Watcher:127.0.0.1:57803 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2434419 T8100 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2434426 T8100 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2434429 T8162 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e54ebd5 name:ZooKeeperConnection Watcher:127.0.0.1:57803/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2434430 T8100 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2434443 T8100 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2435325 T8100 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57831_x%2Fm
   [junit4]   2> 2435327 T8100 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57831_x%2Fm
   [junit4]   2> 2435333 T8144 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 2435334 T8162 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 2435335 T8122 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 2435336 T8131 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 2435345 T8163 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 2435345 T8163 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2435347 T8163 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 2435348 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2435348 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2435348 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2435351 T8123 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2435352 T8123 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:57831/x/m",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:57831_x%2Fm",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 2435352 T8123 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 2435352 T8123 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 2435357 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2435358 T8144 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> 2435359 T8162 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> 2435360 T8131 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> 2435360 T8122 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> 2436302 T8163 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 2436302 T8163 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 2436303 T8163 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 2436303 T8163 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 2436304 T8163 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 2436304 T8163 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-004\collection1\'
   [junit4]   2> 2436307 T8163 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001/tempDir-004/collection1/lib/.svn/' to classloader
   [junit4]   2> 2436308 T8163 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001/tempDir-004/collection1/lib/classes/' to classloader
   [junit4]   2> 2436308 T8163 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001/tempDir-004/collection1/lib/README' to classloader
   [junit4]   2> 2436353 T8163 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
   [junit4]   2> 2436363 T8163 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 2436366 T8163 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 2436369 T8163 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 2436512 T8163 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 2436512 T8163 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 2436513 T8163 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 2436519 T8163 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2436520 T8163 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2436536 T8163 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2436539 T8163 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2436555 T8163 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2436558 T8163 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2436558 T8163 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2436558 T8163 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2436560 T8163 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2436560 T8163 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2436560 T8163 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 2436560 T8163 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 2436561 T8163 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-004\collection1\, dataDir=.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-001/jetty2\
   [junit4]   2> 2436561 T8163 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@ba91290
   [junit4]   2> 2436563 T8163 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-001/jetty2\
   [junit4]   2> 2436563 T8163 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-001/jetty2\index/
   [junit4]   2> 2436563 T8163 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-001\jetty2\index' doesn't exist. Creating new index...
   [junit4]   2> 2436563 T8163 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-001/jetty2\index
   [junit4]   2> 2436564 T8163 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=42, maxMergeAtOnceExplicit=33, maxMergedSegmentMB=29.052734375, floorSegmentMB=1.40234375, forceMergeDeletesPctAllowed=8.18380897088708, segmentsPerTier=18.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.17563226751976968
   [junit4]   2> 2436564 T8163 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@59026854 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@66568128),segFN=segments_1,generation=1}
   [junit4]   2> 2436564 T8163 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2436567 T8163 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 2436567 T8163 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 2436568 T8163 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 2436568 T8163 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2436568 T8163 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2436568 T8163 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 2436569 T8163 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2436569 T8163 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2436569 T8163 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 2436570 T8163 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 2436571 T8163 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 2436571 T8163 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 2436571 T8163 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 2436572 T8163 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 2436572 T8163 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 2436573 T8163 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 2436579 T8163 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2436583 T8163 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 2436583 T8163 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 2436583 T8163 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=22, maxMergeAtOnceExplicit=35, maxMergedSegmentMB=96.375, floorSegmentMB=2.078125, forceMergeDeletesPctAllowed=23.681496182561734, segmentsPerTier=21.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7689713790832439
   [junit4]   2> 2436583 T8163 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@59026854 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@66568128),segFN=segments_1,generation=1}
   [junit4]   2> 2436583 T8163 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2436583 T8163 oass.SolrIndexSearcher.<init> Opening Searcher@2ae85533[collection1] main
   [junit4]   2> 2436583 T8163 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 2436585 T8163 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 2436585 T8163 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 2436586 T8163 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 2436586 T8163 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 2436586 T8163 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2436587 T8163 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 2436587 T8163 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2436587 T8163 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 2436587 T8163 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 2436592 T8164 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2ae85533[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 2436593 T8163 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 2436594 T8167 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57831/x/m collection:collection1 shard:shard1
   [junit4]   2> 2436595 T8100 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 2436596 T8100 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 2436597 T8167 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 2436606 T8167 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 2436610 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2436612 T8167 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 2436612 T8167 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C4854 name=collection1 org.apache.solr.core.SolrCore@14e60bc3 url=http://127.0.0.1:57831/x/m/collection1 node=127.0.0.1:57831_x%2Fm C4854_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:57831/x/m, core=collection1, node_name=127.0.0.1:57831_x%2Fm}
   [junit4]   2> 2436612 T8167 C4854 P57831 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57831/x/m/collection1/
   [junit4]   2> 2436612 T8167 C4854 P57831 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 2436614 T8167 C4854 P57831 oasc.SyncStrategy.syncToMe http://127.0.0.1:57831/x/m/collection1/ has no replicas
   [junit4]   2> 2436614 T8167 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57831/x/m/collection1/ shard1
   [junit4]   2> 2436614 T8167 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2436616 T8123 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2436625 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2436627 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2436633 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2436747 T8144 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> 2436747 T8162 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> 2436748 T8131 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> 2436749 T8122 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> 2436777 T8167 oasc.ZkController.register We are http://127.0.0.1:57831/x/m/collection1/ and leader is http://127.0.0.1:57831/x/m/collection1/
   [junit4]   2> 2436777 T8167 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57831/x/m
   [junit4]   2> 2436777 T8167 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 2436777 T8167 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 2436777 T8167 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2436781 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2436781 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2436781 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2436784 T8167 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2436786 T8123 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2436787 T8123 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:57831/x/m",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:57831_x%2Fm",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 2436794 T8122 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2436905 T8144 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> 2436907 T8162 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> 2436908 T8131 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> 2436909 T8122 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> 2438553 T8100 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
   [junit4]   2> 2438553 T8100 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 2438557 T8100 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57840
   [junit4]   2> 2438558 T8100 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 2438559 T8100 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2438559 T8100 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-005
   [junit4]   2> 2438559 T8100 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-005\'
   [junit4]   2> 2438593 T8100 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-005\solr.xml
   [junit4]   2> 2438619 T8100 oasc.CoreContainer.<init> New CoreContainer 1985187671
   [junit4]   2> 2438619 T8100 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001\tempDir-005\]
   [junit4]   2> 2438619 T8100 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 2438620 T8100 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 2438620 T8100 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 2438620 T8100 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 2438621 T8100 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 2438621 T8100 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 2438621 T8100 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 2438622 T8100 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 2438622 T8100 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 2438623 T8100 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 2438623 T8100 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 2438623 T8100 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 2438624 T8100 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57803/solr
   [junit4]   2> 2438624 T8100 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2438627 T8100 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2438635 T8178 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@713cdfaa name:ZooKeeperConnection Watcher:127.0.0.1:57803 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2438636 T8100 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2438639 T8102 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read a

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

impl.HttpSolrServer$RemoteSolrException: Cannot talk to ZooKeeper - Updates are disabled.
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([24A9853F6A21A3AE:A54F0B271D7EC392]:0)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:554)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:210)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:206)
   [junit4]    > 	at org.apache.solr.client.solrj.request.AbstractUpdateRequest.process(AbstractUpdateRequest.java:124)
   [junit4]    > 	at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:168)
   [junit4]    > 	at org.apache.solr.client.solrj.SolrServer.commit(SolrServer.java:146)
   [junit4]    > 	at org.apache.solr.cloud.BasicDistributedZkTest.testUpdateProcessorsRunOnlyOnce(BasicDistributedZkTest.java:667)
   [junit4]    > 	at org.apache.solr.cloud.BasicDistributedZkTest.doTest(BasicDistributedZkTest.java:376)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:865)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 2556295 T8100 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.BasicDistributedZkTest-24A9853F6A21A3AE-001
   [junit4]   2> 131212 T8099 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
   [junit4]   2> NOTE: test params are: codec=Lucene46: {regex_dup_A_s=PostingsFormat(name=Direct), other_tl1=PostingsFormat(name=TestBloomFilteredLucene41Postings), regex_dup_B_s=PostingsFormat(name=TestBloomFilteredLucene41Postings), SubjectTerms_mfacet=PostingsFormat(name=TestBloomFilteredLucene41Postings), n_l1=PostingsFormat(name=TestBloomFilteredLucene41Postings), multiDefault=Pulsing41(freqCutoff=12 minBlockSize=64 maxBlockSize=210), intDefault=PostingsFormat(name=TestBloomFilteredLucene41Postings), genre_s=PostingsFormat(name=Direct), n_td1=Pulsing41(freqCutoff=12 minBlockSize=64 maxBlockSize=210), n_d1=PostingsFormat(name=TestBloomFilteredLucene41Postings), range_facet_l=PostingsFormat(name=TestBloomFilteredLucene41Postings), n_f1=Pulsing41(freqCutoff=12 minBlockSize=64 maxBlockSize=210), series_t=Pulsing41(freqCutoff=12 minBlockSize=64 maxBlockSize=210), n_tl1=Pulsing41(freqCutoff=12 minBlockSize=64 maxBlockSize=210), oddField_s=PostingsFormat(name=Direct), n_tf1=PostingsFormat(name=TestBloomFilteredLucene41Postings), price=PostingsFormat(name=Direct), a_t=PostingsFormat(name=TestBloomFilteredLucene41Postings), cat=PostingsFormat(name=TestBloomFilteredLucene41Postings), a_si=Pulsing41(freqCutoff=12 minBlockSize=64 maxBlockSize=210), inStock=PostingsFormat(name=Direct), sequence_i=PostingsFormat(name=Direct), id=PostingsFormat(name=NestedPulsing), text=PostingsFormat(name=Direct), timestamp=PostingsFormat(name=TestBloomFilteredLucene41Postings), foo_i=Pulsing41(freqCutoff=12 minBlockSize=64 maxBlockSize=210), val_i=PostingsFormat(name=NestedPulsing), range_facet_sl=PostingsFormat(name=Direct), range_facet_si=Pulsing41(freqCutoff=12 minBlockSize=64 maxBlockSize=210), n_dt1=Pulsing41(freqCutoff=12 minBlockSize=64 maxBlockSize=210), author_t=Pulsing41(freqCutoff=12 minBlockSize=64 maxBlockSize=210), n_ti1=PostingsFormat(name=NestedPulsing), rnd_b=PostingsFormat(name=NestedPulsing), _version_=PostingsFormat(name=TestBloomFilteredLucene41Postings), foo_b=PostingsFormat(name=Direct), n_tdt1=PostingsFormat(name=TestBloomFilteredLucene41Postings), name=PostingsFormat(name=NestedPulsing), foo_d=PostingsFormat(name=NestedPulsing), foo_f=PostingsFormat(name=Direct)}, docValues:{}, sim=DefaultSimilarity, locale=lv_LV, timezone=Europe/Sofia
   [junit4]   2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.8.0_20-ea (64-bit)/cpus=2,threads=1,free=86982968,total=344813568
   [junit4]   2> NOTE: All tests run in this JVM: [HttpPartitionTest, TestUpdate, FastVectorHighlighterTest, TestUtils, CacheHeaderTest, TestComplexPhraseQParserPlugin, TestLRUCache, TestCollationKeyRangeQueries, CoreAdminHandlerTest, TestSerializedLuceneMatchVersion, TestDocumentBuilder, TestSolrXMLSerializer, RankQueryTest, TestSchemaSimilarityResource, TestCollectionAPI, NumericFieldsTest, TestSearchPerf, TestJmxIntegration, TestIndexSearcher, SortByFunctionTest, TestRangeQuery, TestManagedSynonymFilterFactory, StatelessScriptUpdateProcessorFactoryTest, TermVectorComponentDistributedTest, UpdateRequestProcessorFactoryTest, TestManagedSchema, ChaosMonkeySafeLeaderTest, SolrInfoMBeanTest, TestInitQParser, BinaryUpdateRequestHandlerTest, OverseerCollectionProcessorTest, FieldMutatingUpdateProcessorTest, XmlUpdateRequestHandlerTest, TestManagedSchemaFieldResource, TestCopyFieldCollectionResource, TestSurroundQueryParser, OpenCloseCoreStressTest, PolyFieldTest, UpdateParamsTest, TestJmxMonitoredMap, PrimUtilsTest, TestUniqueKeyFieldResource, TestShardHandlerFactory, DistanceFunctionTest, TestInfoStreamLogging, TestRecoveryHdfs, HdfsLockFactoryTest, AtomicUpdatesTest, TestSolrDeletionPolicy1, RAMDirectoryFactoryTest, TestNoOpRegenerator, OutputWriterTest, EchoParamsTest, TestWriterPerf, QueryResultKeyTest, SpellingQueryConverterTest, TestSimpleQParserPlugin, DirectUpdateHandlerTest, DistributedExpandComponentTest, TestStressLucene, EnumFieldTest, PluginInfoTest, AssignTest, InfoHandlerTest, OverseerRolesTest, HdfsSyncSliceTest, TermVectorComponentTest, SolrPluginUtilsTest, TestComponentsName, PathHierarchyTokenizerFactoryTest, CursorPagingTest, ShowFileRequestHandlerTest, DisMaxRequestHandlerTest, TestCollationField, DateFieldTest, StressHdfsTest, TestSolrCoreProperties, SpatialFilterTest, TestAtomicUpdateErrorCases, TestFieldCollectionResource, TestStressVersions, TestTrie, MultiTermTest, DistributedTermsComponentTest, SyncSliceTest, CollectionsAPIAsyncDistributedZkTest, DistributedDebugComponentTest, ReturnFieldsTest, ShardRoutingTest, TestFieldTypeCollectionResource, TestManagedResourceStorage, ClusterStateTest, TestDistributedMissingSort, TestSuggestSpellingConverter, HdfsBasicDistributedZk2Test, TestPhraseSuggestions, DebugComponentTest, TestOmitPositions, TestSystemIdResolver, TestRTGBase, TestRemoteStreaming, TestCollapseQParserPlugin, TestBinaryField, TestFastWriter, ConnectionManagerTest, TestValueSourceCache, ReplicationFactorTest, IndexSchemaRuntimeFieldTest, DistribDocExpirationUpdateProcessorTest, BadCopyFieldTest, SliceStateTest, SimplePostToolTest, TestCodecSupport, CollectionsAPIDistributedZkTest, QueryParsingTest, SpellCheckComponentTest, TestRestManager, TestExtendedDismaxParser, TestClassNameShortening, TestShortCircuitedRequests, TestLFUCache, FullSolrCloudDistribCmdsTest, SolrCoreTest, FileUtilsTest, TestReplicationHandler, ChaosMonkeyNothingIsSafeTest, SystemInfoHandlerTest, TestNumberUtils, RemoteQueryErrorTest, ConvertedLegacyTest, SliceStateUpdateTest, AnalysisAfterCoreReloadTest, PreAnalyzedUpdateProcessorTest, DistributedQueryComponentOptimizationTest, SuggesterTest, TestManagedResource, TestSort, TestFaceting, TestPseudoReturnFields, XsltUpdateRequestHandlerTest, ExternalFileFieldSortTest, SolrCmdDistributorTest, LukeRequestHandlerTest, TestRequestStatusCollectionAPI, TestArbitraryIndexDir, HighlighterConfigTest, NoCacheHeaderTest, StandardRequestHandlerTest, TestRecovery, TestPostingsSolrHighlighter, TestBadConfig, TestCloudInspectUtil, TestRandomMergePolicy, TestFunctionQuery, AliasIntegrationTest, DirectSolrConnectionTest, NotRequiredUniqueKeyTest, PrimitiveFieldTypeTest, MinimalSchemaTest, TestDistributedSearch, TestNonDefinedSimilarityFactory, TestReload, ZkSolrClientTest, TestBlendedInfixSuggestions, TestSweetSpotSimilarityFactory, TestZkChroot, TestSolrXml, TestFiltering, TestQueryTypes, TriLevelCompositeIdRoutingTest, TestCloudManagedSchema, JSONWriterTest, TestPartialUpdateDeduplication, SoftAutoCommitTest, FieldAnalysisRequestHandlerTest, TestExceedMaxTermLength, TestFileDictionaryLookup, TestSolrQueryParserResource, CachingDirectoryFactoryTest, ResourceLoaderTest, TestMaxScoreQueryParser, TestBinaryResponseWriter, MBeansHandlerTest, TestDynamicFieldCollectionResource, SolrRequestParserTest, OpenExchangeRatesOrgProviderTest, CurrencyFieldXmlFileTest, TestStressReorder, HdfsChaosMonkeySafeLeaderTest, BasicDistributedZkTest]
   [junit4] Completed in 132.12s, 1 test, 1 error <<< FAILURES!

[...truncated 616 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:467: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:447: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:45: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\extra-targets.xml:37: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build.xml:189: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\common-build.xml:496: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1297: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:921: There were test failures: 396 suites, 1640 tests, 1 error, 41 ignored (20 assumptions)

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



[JENKINS] Lucene-Solr-4.x-Windows (32bit/jdk1.7.0_55) - Build # 3971 - Still Failing!

Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/3971/
Java: 32bit/jdk1.7.0_55 -client -XX:+UseSerialGC

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

Error Message:
Task 1001 not found in completed tasks. expected:<found 1001 in [comple]ted tasks> but was:<found 1001 in [submit]ted tasks>

Stack Trace:
org.junit.ComparisonFailure: Task 1001 not found in completed tasks. expected:<found 1001 in [comple]ted tasks> but was:<found 1001 in [submit]ted tasks>
	at __randomizedtesting.SeedInfo.seed([DF23183016DCC764:5EC596286183A758]:0)
	at org.junit.Assert.assertEquals(Assert.java:125)
	at org.apache.solr.cloud.TestRequestStatusCollectionAPI.doTest(TestRequestStatusCollectionAPI.java:125)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:865)
	at sun.reflect.GeneratedMethodAccessor46.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
	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:65)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
	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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
	at java.lang.Thread.run(Thread.java:745)




Build Log:
[...truncated 11673 lines...]
   [junit4] Suite: org.apache.solr.cloud.TestRequestStatusCollectionAPI
   [junit4]   2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\init-core-data-001
   [junit4]   2> 5096768 T13482 oas.SolrTestCaseJ4.startTrackingSearchers WARN startTrackingSearchers: numOpens=6 numCloses=6
   [junit4]   2> 5096768 T13482 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /p_/lp
   [junit4]   2> 5096774 T13482 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> 5096776 T13482 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 5096778 T13483 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 5096859 T13482 oasc.ZkTestServer.run start zk server on port:53182
   [junit4]   2> 5096860 T13482 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 5096867 T13489 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@132705 name:ZooKeeperConnection Watcher:127.0.0.1:53182 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 5096867 T13482 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 5096867 T13482 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 5096881 T13482 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 5096883 T13491 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ae844c name:ZooKeeperConnection Watcher:127.0.0.1:53182/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 5096884 T13482 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 5096884 T13482 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 5096891 T13482 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 5096896 T13482 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 5096901 T13482 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 5096906 T13482 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 5096906 T13482 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 5096915 T13482 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\schema15.xml to /configs/conf1/schema.xml
   [junit4]   2> 5096916 T13482 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 5096922 T13482 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 5096922 T13482 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 5096929 T13482 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 5096930 T13482 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 5096936 T13482 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 5096937 T13482 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 5096941 T13482 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 5096942 T13482 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 5096949 T13482 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 5096949 T13482 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 5096955 T13482 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 5096956 T13482 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 5096960 T13482 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 5096960 T13482 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 5096965 T13482 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 5096966 T13482 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 5096970 T13482 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\core\src\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 5096971 T13482 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 5098929 T13482 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 5098936 T13482 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53189
   [junit4]   2> 5098937 T13482 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 5098937 T13482 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 5098938 T13482 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-002
   [junit4]   2> 5098938 T13482 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-002\'
   [junit4]   2> 5098976 T13482 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-002\solr.xml
   [junit4]   2> 5099076 T13482 oasc.CoreContainer.<init> New CoreContainer 6908191
   [junit4]   2> 5099076 T13482 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-002\]
   [junit4]   2> 5099078 T13482 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 5099079 T13482 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 5099079 T13482 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 5099080 T13482 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 5099080 T13482 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 5099080 T13482 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 5099081 T13482 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 5099081 T13482 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 5099082 T13482 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 5099083 T13482 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 5099084 T13482 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 5099084 T13482 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 5099084 T13482 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53182/solr
   [junit4]   2> 5099085 T13482 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 5099087 T13482 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 5099092 T13502 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@748f28 name:ZooKeeperConnection Watcher:127.0.0.1:53182 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 5099093 T13482 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 5099100 T13482 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 5099103 T13504 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a233af name:ZooKeeperConnection Watcher:127.0.0.1:53182/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 5099104 T13482 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 5099106 T13482 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 5099111 T13482 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 5099117 T13482 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 5099123 T13482 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 5099134 T13482 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 5099140 T13482 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 5099144 T13482 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53189_p_%2Flp
   [junit4]   2> 5099146 T13482 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53189_p_%2Flp
   [junit4]   2> 5099152 T13482 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 5099158 T13482 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 5099166 T13482 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:53189_p_%2Flp
   [junit4]   2> 5099166 T13482 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 5099169 T13482 oasc.Overseer.start Overseer (id=91802647591387139-127.0.0.1:53189_p_%2Flp-n_0000000000) starting
   [junit4]   2> 5099174 T13482 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 5099196 T13506 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 5099197 T13482 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 5099203 T13482 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 5099207 T13482 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 5099212 T13505 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 5099224 T13507 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 5099224 T13507 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 5099226 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5099226 T13507 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 5099228 T13505 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 5099229 T13505 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:53189/p_/lp",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53189_p_%2Flp",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 5099229 T13505 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 5099230 T13505 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 5099235 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5099236 T13504 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> 5100041 T13507 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 5100041 T13507 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 5100042 T13507 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 5100042 T13507 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 5100044 T13507 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 5100045 T13507 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-002\collection1\'
   [junit4]   2> 5100048 T13507 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001/tempDir-002/collection1/lib/.svn/' to classloader
   [junit4]   2> 5100049 T13507 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001/tempDir-002/collection1/lib/classes/' to classloader
   [junit4]   2> 5100050 T13507 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001/tempDir-002/collection1/lib/README' to classloader
   [junit4]   2> 5100148 T13507 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
   [junit4]   2> 5100231 T13507 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 5100234 T13507 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 5100246 T13507 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 5100921 T13507 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 5100925 T13507 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 5100927 T13507 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 5100933 T13507 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 5100970 T13507 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 5100970 T13507 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 5100971 T13507 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-002\collection1\, dataDir=.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-001/control/data\
   [junit4]   2> 5100971 T13507 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@30cf28
   [junit4]   2> 5100972 T13507 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-001/control/data\
   [junit4]   2> 5100972 T13507 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-001/control/data\index/
   [junit4]   2> 5100972 T13507 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-001\control\data\index' doesn't exist. Creating new index...
   [junit4]   2> 5100972 T13507 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-001/control/data\index
   [junit4]   2> 5100973 T13507 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=43, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 5100974 T13507 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@8fb2ed lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@182ca66),segFN=segments_1,generation=1}
   [junit4]   2> 5100974 T13507 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 5100976 T13507 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 5100977 T13507 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 5100978 T13507 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 5100978 T13507 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 5100978 T13507 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 5100979 T13507 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 5100979 T13507 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 5100979 T13507 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 5100979 T13507 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 5100980 T13507 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 5100981 T13507 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 5100981 T13507 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 5100982 T13507 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 5100982 T13507 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 5100983 T13507 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 5100983 T13507 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 5100991 T13507 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 5100998 T13507 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 5100998 T13507 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 5100999 T13507 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=38, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8345388088693083]
   [junit4]   2> 5101000 T13507 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@8fb2ed lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@182ca66),segFN=segments_1,generation=1}
   [junit4]   2> 5101000 T13507 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 5101001 T13507 oass.SolrIndexSearcher.<init> Opening Searcher@4f36eb[collection1] main
   [junit4]   2> 5101001 T13507 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 5101002 T13507 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 5101003 T13507 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 5101003 T13507 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 5101003 T13507 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 5101004 T13507 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 5101005 T13507 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 5101005 T13507 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 5101006 T13507 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 5101006 T13507 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 5101008 T13508 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4f36eb[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 5101009 T13507 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 5101011 T13511 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53189/p_/lp collection:control_collection shard:shard1
   [junit4]   2> 5101011 T13482 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 5101011 T13482 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 5101013 T13511 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 5101014 T13482 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 5101017 T13513 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@96cf99 name:ZooKeeperConnection Watcher:127.0.0.1:53182/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 5101017 T13482 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 5101019 T13482 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 5101025 T13482 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 5101027 T13511 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 5101031 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5101033 T13511 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 5101033 T13511 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C4085 name=collection1 org.apache.solr.core.SolrCore@7a6ab2 url=http://127.0.0.1:53189/p_/lp/collection1 node=127.0.0.1:53189_p_%2Flp C4085_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:53189/p_/lp, core=collection1, node_name=127.0.0.1:53189_p_%2Flp}
   [junit4]   2> 5101033 T13511 C4085 P53189 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53189/p_/lp/collection1/
   [junit4]   2> 5101033 T13511 C4085 P53189 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 5101033 T13511 C4085 P53189 oasc.SyncStrategy.syncToMe http://127.0.0.1:53189/p_/lp/collection1/ has no replicas
   [junit4]   2> 5101034 T13511 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53189/p_/lp/collection1/ shard1
   [junit4]   2> 5101036 T13511 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 5101038 T13505 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 5101049 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5101051 T13504 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> 5101053 T13513 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> 5101062 T13505 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 5101066 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5101144 T13504 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> 5101145 T13513 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> 5101174 T13511 oasc.ZkController.register We are http://127.0.0.1:53189/p_/lp/collection1/ and leader is http://127.0.0.1:53189/p_/lp/collection1/
   [junit4]   2> 5101174 T13511 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53189/p_/lp
   [junit4]   2> 5101174 T13511 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 5101174 T13511 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 5101174 T13511 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 5101177 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5101177 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5101177 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5101179 T13511 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 5101182 T13505 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 5101182 T13505 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:53189/p_/lp",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53189_p_%2Flp",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 5101186 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5101263 T13504 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> 5101264 T13513 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> 5102629 T13482 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 5102630 T13482 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 5102632 T13482 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53201
   [junit4]   2> 5102634 T13482 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 5102634 T13482 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 5102634 T13482 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-003
   [junit4]   2> 5102635 T13482 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-003\'
   [junit4]   2> 5102666 T13482 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-003\solr.xml
   [junit4]   2> 5102761 T13482 oasc.CoreContainer.<init> New CoreContainer 28326285
   [junit4]   2> 5102762 T13482 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-003\]
   [junit4]   2> 5102765 T13482 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 5102765 T13482 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 5102765 T13482 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 5102766 T13482 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 5102766 T13482 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 5102767 T13482 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 5102768 T13482 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 5102768 T13482 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 5102768 T13482 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 5102769 T13482 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 5102770 T13482 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 5102770 T13482 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 5102770 T13482 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53182/solr
   [junit4]   2> 5102771 T13482 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 5102773 T13482 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 5102776 T13524 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@928d29 name:ZooKeeperConnection Watcher:127.0.0.1:53182 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 5102777 T13482 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 5102779 T13484 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x146260587200005, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 5102781 T13482 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 5102783 T13526 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f65868 name:ZooKeeperConnection Watcher:127.0.0.1:53182/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 5102783 T13482 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 5102795 T13482 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 5103532 T13482 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53201_p_%2Flp
   [junit4]   2> 5103534 T13482 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53201_p_%2Flp
   [junit4]   2> 5103537 T13526 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 5103538 T13504 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 5103539 T13513 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 5103553 T13527 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 5103553 T13527 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 5103555 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5103555 T13527 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 5103555 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5103556 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5103560 T13505 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 5103560 T13505 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:53201/p_/lp",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53201_p_%2Flp",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 5103560 T13505 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 5103561 T13505 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 5103565 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5103567 T13513 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> 5103567 T13526 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> 5103567 T13504 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> 5104289 T13527 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 5104289 T13527 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 5104290 T13527 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 5104291 T13527 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 5104292 T13527 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 5104292 T13527 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-003\collection1\'
   [junit4]   2> 5104295 T13527 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001/tempDir-003/collection1/lib/.svn/' to classloader
   [junit4]   2> 5104296 T13527 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001/tempDir-003/collection1/lib/classes/' to classloader
   [junit4]   2> 5104297 T13527 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001/tempDir-003/collection1/lib/README' to classloader
   [junit4]   2> 5104371 T13527 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
   [junit4]   2> 5104444 T13527 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 5104447 T13527 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 5104458 T13527 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 5105075 T13527 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 5105079 T13527 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 5105081 T13527 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 5105088 T13527 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 5105118 T13527 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 5105118 T13527 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 5105119 T13527 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-003\collection1\, dataDir=.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-001/jetty1\
   [junit4]   2> 5105120 T13527 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@30cf28
   [junit4]   2> 5105121 T13527 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-001/jetty1\
   [junit4]   2> 5105121 T13527 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-001/jetty1\index/
   [junit4]   2> 5105121 T13527 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-001\jetty1\index' doesn't exist. Creating new index...
   [junit4]   2> 5105122 T13527 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-001/jetty1\index
   [junit4]   2> 5105123 T13527 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=43, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 5105123 T13527 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1fb883e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@dc413f),segFN=segments_1,generation=1}
   [junit4]   2> 5105123 T13527 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 5105128 T13527 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 5105128 T13527 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 5105129 T13527 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 5105129 T13527 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 5105130 T13527 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 5105130 T13527 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 5105131 T13527 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 5105131 T13527 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 5105131 T13527 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 5105133 T13527 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 5105133 T13527 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 5105133 T13527 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 5105133 T13527 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 5105135 T13527 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 5105136 T13527 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 5105136 T13527 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 5105147 T13527 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 5105154 T13527 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 5105154 T13527 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 5105155 T13527 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=38, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8345388088693083]
   [junit4]   2> 5105156 T13527 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1fb883e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@dc413f),segFN=segments_1,generation=1}
   [junit4]   2> 5105156 T13527 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 5105156 T13527 oass.SolrIndexSearcher.<init> Opening Searcher@1529d5d[collection1] main
   [junit4]   2> 5105156 T13527 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 5105158 T13527 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 5105158 T13527 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 5105159 T13527 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 5105159 T13527 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 5105159 T13527 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 5105161 T13527 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 5105161 T13527 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 5105161 T13527 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 5105161 T13527 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 5105166 T13528 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1529d5d[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 5105171 T13527 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 5105171 T13531 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53201/p_/lp collection:collection1 shard:shard2
   [junit4]   2> 5105172 T13482 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 5105172 T13482 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 5105174 T13531 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 5105187 T13531 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 5105196 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5105196 T13531 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 5105196 T13531 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C4086 name=collection1 org.apache.solr.core.SolrCore@1307dc9 url=http://127.0.0.1:53201/p_/lp/collection1 node=127.0.0.1:53201_p_%2Flp C4086_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:53201/p_/lp, core=collection1, node_name=127.0.0.1:53201_p_%2Flp}
   [junit4]   2> 5105196 T13531 C4086 P53201 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53201/p_/lp/collection1/
   [junit4]   2> 5105197 T13531 C4086 P53201 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 5105197 T13531 C4086 P53201 oasc.SyncStrategy.syncToMe http://127.0.0.1:53201/p_/lp/collection1/ has no replicas
   [junit4]   2> 5105197 T13531 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53201/p_/lp/collection1/ shard2
   [junit4]   2> 5105198 T13531 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 5105200 T13505 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 5105208 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5105210 T13513 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> 5105211 T13504 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> 5105211 T13526 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> 5105221 T13505 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 5105226 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5105303 T13526 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> 5105304 T13504 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> 5105304 T13513 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> 5105329 T13531 oasc.ZkController.register We are http://127.0.0.1:53201/p_/lp/collection1/ and leader is http://127.0.0.1:53201/p_/lp/collection1/
   [junit4]   2> 5105329 T13531 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53201/p_/lp
   [junit4]   2> 5105329 T13531 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 5105329 T13531 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 5105329 T13531 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 5105332 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5105332 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5105332 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5105333 T13531 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 5105335 T13505 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 5105336 T13505 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:53201/p_/lp",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53201_p_%2Flp",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 5105340 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5105417 T13526 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> 5105419 T13504 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> 5105419 T13513 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> 5106765 T13482 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 5106767 T13482 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 5106770 T13482 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53210
   [junit4]   2> 5106772 T13482 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 5106772 T13482 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 5106772 T13482 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-004
   [junit4]   2> 5106772 T13482 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-004\'
   [junit4]   2> 5106822 T13482 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-004\solr.xml
   [junit4]   2> 5106920 T13482 oasc.CoreContainer.<init> New CoreContainer 32505949
   [junit4]   2> 5106920 T13482 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-004\]
   [junit4]   2> 5106923 T13482 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 5106923 T13482 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 5106923 T13482 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 5106923 T13482 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 5106925 T13482 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 5106925 T13482 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 5106925 T13482 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 5106925 T13482 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 5106926 T13482 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 5106926 T13482 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 5106926 T13482 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 5106928 T13482 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 5106928 T13482 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53182/solr
   [junit4]   2> 5106928 T13482 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 5106931 T13482 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 5106937 T13542 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a7fd8a name:ZooKeeperConnection Watcher:127.0.0.1:53182 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 5106938 T13482 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 5106942 T13482 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 5106944 T13544 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1aa4b09 name:ZooKeeperConnection Watcher:127.0.0.1:53182/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 5106946 T13482 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 5106957 T13482 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 5107694 T13482 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53210_p_%2Flp
   [junit4]   2> 5107696 T13482 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53210_p_%2Flp
   [junit4]   2> 5107705 T13526 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 5107705 T13504 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 5107706 T13544 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 5107707 T13513 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 5107721 T13545 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 5107721 T13545 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 5107725 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5107725 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5107725 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5107726 T13545 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 5107729 T13505 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 5107730 T13505 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:53210/p_/lp",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53210_p_%2Flp",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 5107730 T13505 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 5107731 T13505 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 5107737 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5107738 T13526 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> 5107738 T13504 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> 5107739 T13544 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> 5107739 T13513 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> 5108444 T13545 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 5108444 T13545 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 5108446 T13545 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 5108446 T13545 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 5108449 T13545 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 5108449 T13545 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-004\collection1\'
   [junit4]   2> 5108453 T13545 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001/tempDir-004/collection1/lib/.svn/' to classloader
   [junit4]   2> 5108456 T13545 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001/tempDir-004/collection1/lib/classes/' to classloader
   [junit4]   2> 5108458 T13545 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001/tempDir-004/collection1/lib/README' to classloader
   [junit4]   2> 5108525 T13545 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
   [junit4]   2> 5108595 T13545 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 5108597 T13545 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 5108606 T13545 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 5109171 T13545 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 5109175 T13545 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 5109177 T13545 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 5109183 T13545 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 5109215 T13545 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 5109215 T13545 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 5109216 T13545 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-004\collection1\, dataDir=.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-001/jetty2\
   [junit4]   2> 5109216 T13545 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@30cf28
   [junit4]   2> 5109216 T13545 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-001/jetty2\
   [junit4]   2> 5109216 T13545 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-001/jetty2\index/
   [junit4]   2> 5109217 T13545 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-001\jetty2\index' doesn't exist. Creating new index...
   [junit4]   2> 5109217 T13545 oasc.CachingDirectoryFactory.get return new directory for .\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-001/jetty2\index
   [junit4]   2> 5109218 T13545 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=43, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 5109218 T13545 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1949b82 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1bc35c4),segFN=segments_1,generation=1}
   [junit4]   2> 5109218 T13545 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 5109221 T13545 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 5109221 T13545 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 5109222 T13545 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 5109222 T13545 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 5109222 T13545 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 5109223 T13545 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 5109223 T13545 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 5109223 T13545 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 5109223 T13545 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 5109224 T13545 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 5109225 T13545 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 5109225 T13545 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 5109225 T13545 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 5109226 T13545 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 5109226 T13545 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 5109236 T13545 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 5109243 T13545 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 5109248 T13545 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 5109249 T13545 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 5109250 T13545 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=38, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8345388088693083]
   [junit4]   2> 5109250 T13545 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1949b82 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1bc35c4),segFN=segments_1,generation=1}
   [junit4]   2> 5109250 T13545 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 5109251 T13545 oass.SolrIndexSearcher.<init> Opening Searcher@ed10ea[collection1] main
   [junit4]   2> 5109251 T13545 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 5109252 T13545 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 5109253 T13545 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 5109254 T13545 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 5109254 T13545 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 5109254 T13545 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 5109255 T13545 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 5109255 T13545 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 5109256 T13545 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 5109256 T13545 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 5109259 T13546 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@ed10ea[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 5109262 T13545 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 5109264 T13549 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53210/p_/lp collection:collection1 shard:shard1
   [junit4]   2> 5109264 T13482 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 5109265 T13482 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 5109266 T13549 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 5109275 T13549 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 5109279 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5109280 T13549 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 5109280 T13549 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C4087 name=collection1 org.apache.solr.core.SolrCore@12d0d42 url=http://127.0.0.1:53210/p_/lp/collection1 node=127.0.0.1:53210_p_%2Flp C4087_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:53210/p_/lp, core=collection1, node_name=127.0.0.1:53210_p_%2Flp}
   [junit4]   2> 5109281 T13549 C4087 P53210 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53210/p_/lp/collection1/
   [junit4]   2> 5109281 T13549 C4087 P53210 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 5109281 T13549 C4087 P53210 oasc.SyncStrategy.syncToMe http://127.0.0.1:53210/p_/lp/collection1/ has no replicas
   [junit4]   2> 5109282 T13549 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53210/p_/lp/collection1/ shard1
   [junit4]   2> 5109282 T13549 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 5109283 T13505 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 5109294 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5109296 T13526 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> 5109297 T13504 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> 5109297 T13544 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> 5109297 T13513 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> 5109312 T13505 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 5109317 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5109398 T13526 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> 5109399 T13513 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> 5109400 T13544 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> 5109400 T13504 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> 5109411 T13549 oasc.ZkController.register We are http://127.0.0.1:53210/p_/lp/collection1/ and leader is http://127.0.0.1:53210/p_/lp/collection1/
   [junit4]   2> 5109411 T13549 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53210/p_/lp
   [junit4]   2> 5109411 T13549 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 5109411 T13549 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 5109411 T13549 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 5109413 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5109413 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5109413 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5109417 T13549 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 5109418 T13505 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 5109419 T13505 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:53210/p_/lp",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53210_p_%2Flp",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 5109424 T13504 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 5109494 T13526 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> 5109495 T13513 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> 5109495 T13544 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> 5109495 T13504 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> 5110763 T13482 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
   [junit4]   2> 5110764 T13482 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 5110767 T13482 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53219
   [junit4]   2> 5110767 T13482 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 5110767 T13482 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 5110767 T13482 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-005
   [junit4]   2> 5110769 T13482 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-005\'
   [junit4]   2> 5110801 T13482 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-005\solr.xml
   [junit4]   2> 5110902 T13482 oasc.CoreContainer.<init> New CoreContainer 33020028
   [junit4]   2> 5110903 T13482 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001\tempDir-005\]
   [junit4]   2> 5110905 T13482 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 5110906 T13482 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 5110906 T13482 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 5110906 T13482 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 5110906 T13482 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 5110907 T13482 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 5110908 T13482 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 5110908 T13482 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 5110908 T13482 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 5110909 T13482 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 5110910 T13482 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 5110910 T13482 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 5110910 T13482 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53182/solr
   [junit4]   2> 5110910 T13482 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 5110912 T13482 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 5110921 T13560 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a5c235 name:ZooKeeperConnection Watcher:127.0.0.1:53182 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 5110921 T13482 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 5110923 T13484 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x146260587200009, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 5110925 T13482 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 5110927 T13562 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f44803 name:ZooKeeperConnection Watcher:127.0.0.1:53182/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 5110928 T13482 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 5110942 T13482 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 5111606 T13482 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53219_p_%2Flp
   [junit4]   2> 5111608 T13482 oascc.SolrZkClient.makePath makePath

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

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> 5131242 T13582 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> NOTE: leaving temporary files on disk at: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solr.cloud.TestRequestStatusCollectionAPI-DF23183016DCC764-001
   [junit4]   2> NOTE: test params are: codec=Lucene45, sim=DefaultSimilarity, locale=ar_AE, timezone=Africa/Dakar
   [junit4]   2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.7.0_55 (32-bit)/cpus=2,threads=1,free=111800168,total=363884544
   [junit4]   2> NOTE: All tests run in this JVM: [MultiTermTest, SearchHandlerTest, HdfsBasicDistributedZkTest, TestInitQParser, DirectSolrConnectionTest, TestDFRSimilarityFactory, TestSimpleQParserPlugin, TestTrie, TestSolrXMLSerializer, TimeZoneUtilsTest, TestFiltering, DistribCursorPagingTest, TestFileDictionaryLookup, CurrencyFieldXmlFileTest, TestMultiCoreConfBootstrap, TestBlendedInfixSuggestions, TestSolrQueryParserResource, CurrencyFieldOpenExchangeTest, DocValuesMissingTest, TestShardHandlerFactory, TestPartialUpdateDeduplication, SimplePostToolTest, TestSolrQueryParser, FileBasedSpellCheckerTest, SuggestComponentTest, TestDistributedMissingSort, TestAnalyzedSuggestions, TestQueryTypes, FastVectorHighlighterTest, HdfsSyncSliceTest, SolrPluginUtilsTest, ZkControllerTest, TestReversedWildcardFilterFactory, SyncSliceTest, TestCodecSupport, TestFieldCollectionResource, PreAnalyzedUpdateProcessorTest, TestRandomFaceting, DirectUpdateHandlerTest, WordBreakSolrSpellCheckerTest, TestReplicationHandler, TestSweetSpotSimilarityFactory, ClusterStateTest, FieldMutatingUpdateProcessorTest, TestDynamicFieldResource, TestRealTimeGet, OverseerTest, TestSolrIndexConfig, LegacyHTMLStripCharFilterTest, DocExpirationUpdateProcessorFactoryTest, SliceStateTest, SolrIndexSplitterTest, TestDefaultSearchFieldResource, TestLMDirichletSimilarityFactory, TriLevelCompositeIdRoutingTest, StandardRequestHandlerTest, PluginInfoTest, HttpPartitionTest, UnloadDistributedZkTest, BadCopyFieldTest, TestInfoStreamLogging, ReplicationFactorTest, DateMathParserTest, QueryElevationComponentTest, UpdateParamsTest, TestWriterPerf, TestRTGBase, AtomicUpdatesTest, EnumFieldTest, ReturnFieldsTest, CSVRequestHandlerTest, TestQuerySenderNoQuery, RegexBoostProcessorTest, DistributedQueryElevationComponentTest, TestRemoteStreaming, HdfsCollectionsAPIDistributedZkTest, TermVectorComponentDistributedTest, DistributedDebugComponentTest, ShowFileRequestHandlerTest, DistribDocExpirationUpdateProcessorTest, BasicZkTest, TestManagedResource, TestSuggestSpellingConverter, TestStressUserVersions, CoreAdminRequestStatusTest, TestSolrCoreProperties, CollectionsAPIAsyncDistributedZkTest, TestStressVersions, TestPerFieldSimilarity, TestElisionMultitermQuery, TestNRTOpen, TestJmxIntegration, TestCollationField, SortByFunctionTest, TestRandomDVFaceting, TestCoreDiscovery, TestUtils, CursorMarkTest, MergeStrategyTest, TestGroupingSearch, DocValuesTest, TestUpdate, OverseerRolesTest, TestAnalyzeInfixSuggestions, SuggesterWFSTTest, TestManagedResourceStorage, BinaryUpdateRequestHandlerTest, CopyFieldTest, DocumentAnalysisRequestHandlerTest, TestRestManager, SoftAutoCommitTest, DateFieldTest, DeleteInactiveReplicaTest, TestManagedSchemaFieldResource, SampleTest, SolrXmlInZkTest, MigrateRouteKeyTest, HdfsUnloadDistributedZkTest, TestSolrQueryParserDefaultOperatorResource, TestFieldTypeCollectionResource, TestCloudManagedSchemaAddField, PingRequestHandlerTest, TestUniqueKeyFieldResource, TestStandardQParsers, TestConfigSets, QueryParsingTest, TestNumberUtils, URLClassifyProcessorTest, DistributedTermsComponentTest, BJQParserTest, PeerSyncTest, ShardRoutingCustomTest, SchemaVersionSpecificBehaviorTest, SuggesterTSTTest, QueryEqualityTest, ShardRoutingTest, ZkNodePropsTest, PreAnalyzedFieldTest, TestPHPSerializedResponseWriter, AutoCommitTest, TestFastWriter, TestDynamicFieldCollectionResource, AnalysisErrorHandlingTest, InfoHandlerTest, TestStressRecovery, TestStressReorder, RemoteQueryErrorTest, CoreAdminCreateDiscoverTest, BasicFunctionalityTest, TestCSVResponseWriter, TestSolr4Spatial, TestSchemaResource, LeaderElectionIntegrationTest, TestSearchPerf, TestFastOutputStream, JsonLoaderTest, TestRecoveryHdfs, IndexBasedSpellCheckerTest, TestDistributedGrouping, TestPseudoReturnFields, IndexSchemaTest, LeaderElectionTest, HighlighterTest, TestCharFilters, SuggesterTest, TestReloadAndDeleteDocs, RAMDirectoryFactoryTest, TestCSVLoader, TestAtomicUpdateErrorCases, TestSolrXml, TestCollationFieldDocValues, TestDistributedSearch, TestSchemaVersionResource, DocValuesMultiTest, TestBM25SimilarityFactory, EchoParamsTest, TestCloudInspectUtil, TestSchemaNameResource, DeleteReplicaTest, CoreAdminHandlerTest, SolrIndexConfigTest, TestSurroundQueryParser, TestPhraseSuggestions, BadIndexSchemaTest, NoCacheHeaderTest, DeleteShardTest, TestRangeQuery, TestStressLucene, TestCollapseQParserPlugin, TestNonNRTOpen, PathHierarchyTokenizerFactoryTest, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test, CollectionsAPIDistributedZkTest, OpenCloseCoreStressTest, RecoveryZkTest, FullSolrCloudDistribCmdsTest, ClusterStateUpdateTest, ZkSolrClientTest, TestZkChroot, ZkCLITest, SliceStateUpdateTest, TestFaceting, TestRecovery, TestHashPartitioner, DistributedSpellCheckComponentTest, TestJoin, TestReload, HardAutoCommitTest, TestCoreContainer, SimpleFacetsTest, SolrCoreTest, StatsComponentTest, SpellCheckComponentTest, SolrCmdDistributorTest, ConvertedLegacyTest, TestSort, TestFunctionQuery, TestLazyCores, TestBadConfig, OverseerCollectionProcessorTest, TestIndexSearcher, AnalysisAfterCoreReloadTest, SignatureUpdateProcessorFactoryTest, TestExtendedDismaxParser, SpellCheckCollatorTest, SuggesterFSTTest, SolrRequestParserTest, TestFoldingMultitermQuery, SpatialFilterTest, PolyFieldTest, SolrCoreCheckLockOnStartupTest, TestWordDelimiterFilterFactory, DirectUpdateHandlerOptimizeTest, DefaultValueUpdateProcessorTest, StatelessScriptUpdateProcessorFactoryTest, DistanceFunctionTest, TestSolrDeletionPolicy1, SolrInfoMBeanTest, XsltUpdateRequestHandlerTest, DebugComponentTest, CacheHeaderTest, LukeRequestHandlerTest, DisMaxRequestHandlerTest, TestQueryUtils, DirectSolrSpellCheckerTest, PrimitiveFieldTypeTest, TestOmitPositions, TermsComponentTest, XmlUpdateRequestHandlerTest, RequestHandlersTest, DocumentBuilderTest, TestValueSourceCache, TermVectorComponentTest, TestIndexingPerformance, MoreLikeThisHandlerTest, RequiredFieldsTest, FieldAnalysisRequestHandlerTest, TestArbitraryIndexDir, IndexSchemaRuntimeFieldTest, LoggingHandlerTest, UpdateRequestProcessorFactoryTest, JSONWriterTest, MBeansHandlerTest, UniqFieldsUpdateProcessorFactoryTest, TestComponentsName, CoreContainerCoreInitFailuresTest, TestBinaryResponseWriter, TestLFUCache, HighlighterConfigTest, SOLR749Test, TestQuerySenderListener, AlternateDirectoryTest, ResponseLogComponentTest, BadComponentTest, TestMergePolicyConfig, TestSolrDeletionPolicy2, TestDocSet, TestBinaryField, NumericFieldsTest, MinimalSchemaTest, TestConfig, OutputWriterTest, TestFuzzyAnalyzedSuggestions, ExternalFileFieldSortTest, TestPostingsSolrHighlighter, NotRequiredUniqueKeyTest, TestLuceneMatchVersion, SpellPossibilityIteratorTest, SynonymTokenizerTest, TestXIncludeConfig, TestLMJelinekMercerSimilarityFactory, TestIBSimilarityFactory, TestDefaultSimilarityFactory, TestJmxMonitoredMap, ResourceLoaderTest, ScriptEngineTest, OpenExchangeRatesOrgProviderTest, TestFastLRUCache, ChaosMonkeyNothingIsSafeTest, TestSystemIdResolver, PrimUtilsTest, SpellingQueryConverterTest, DOMUtilTest, TestSolrJ, TestLRUCache, TestDocumentBuilder, SystemInfoHandlerTest, UUIDFieldTest, FileUtilsTest, CircularListTest, CursorPagingTest, SolrTestCaseJ4Test, TestCursorMarkWithoutUniqueKey, TestHighlightDedupGrouping, TestCollationKeyRangeQueries, AliasIntegrationTest, AssignTest, AsyncMigrateRouteKeyTest, ConnectionManagerTest, CustomCollectionTest, MultiThreadedOCPTest, OverseerStatusTest, SSLMigrationTest, ShardSplitTest, TestCollectionAPI, TestDistribDocBasedVersion, TestMiniSolrCloudCluster, TestRequestStatusCollectionAPI]
   [junit4] Completed in 35.41s, 1 test, 1 failure <<< FAILURES!

[...truncated 173 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:467: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:447: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:45: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\extra-targets.xml:37: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build.xml:189: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\common-build.xml:496: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1297: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:921: There were test failures: 396 suites, 1640 tests, 1 failure, 41 ignored (20 assumptions)

Total time: 125 minutes 16 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_55 -client -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure