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 2013/08/05 10:31:21 UTC

[JENKINS] Lucene-Solr-4.x-Windows (32bit/jdk1.8.0-ea-b99) - Build # 3051 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/3051/
Java: 32bit/jdk1.8.0-ea-b99 -server -XX:+UseConcMarkSweepGC

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

Error Message:
Wrong doc count on shard1_0 expected:<83> but was:<84>

Stack Trace:
java.lang.AssertionError: Wrong doc count on shard1_0 expected:<83> but was:<84>
	at __randomizedtesting.SeedInfo.seed([185A3CF194F7C1F7:99BCB2E9E3A8A1CB]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.failNotEquals(Assert.java:647)
	at org.junit.Assert.assertEquals(Assert.java:128)
	at org.junit.Assert.assertEquals(Assert.java:472)
	at org.apache.solr.cloud.ShardSplitTest.checkDocCountsAndShardStates(ShardSplitTest.java:226)
	at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:173)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
	at sun.reflect.GeneratedMethodAccessor42.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:491)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:724)




Build Log:
[...truncated 10353 lines...]
   [junit4] Suite: org.apache.solr.cloud.ShardSplitTest
   [junit4]   2> 2057631 T7041 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 2057635 T7041 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-ShardSplitTest-1375691270841
   [junit4]   2> 2057639 T7041 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 2057640 T7042 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 2057740 T7041 oasc.ZkTestServer.run start zk server on port:58928
   [junit4]   2> 2057741 T7041 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2057770 T7048 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@135d009 name:ZooKeeperConnection Watcher:127.0.0.1:58928 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2057770 T7041 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2057771 T7041 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 2057805 T7041 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2057812 T7050 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f2225f name:ZooKeeperConnection Watcher:127.0.0.1:58928/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2057813 T7041 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2057813 T7041 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 2057825 T7041 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 2057835 T7041 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 2057846 T7041 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 2057857 T7041 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 2057858 T7041 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 2057874 T7041 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\schema15.xml to /configs/conf1/schema.xml
   [junit4]   2> 2057876 T7041 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 2057885 T7041 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 2057887 T7041 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 2057897 T7041 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 2057898 T7041 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 2057908 T7041 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 2057909 T7041 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 2057921 T7041 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 2057922 T7041 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 2057933 T7041 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 2057934 T7041 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 2057946 T7041 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 2057947 T7041 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 2057958 T7041 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 2057958 T7041 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 2058458 T7041 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 2058466 T7041 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58935
   [junit4]   2> 2058466 T7041 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 2058467 T7041 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2058467 T7041 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1375691271178
   [junit4]   2> 2058467 T7041 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1375691271178\'
   [junit4]   2> 2058498 T7041 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1375691271178\solr.xml
   [junit4]   2> 2058510 T7041 oasc.CoreContainer.<init> New CoreContainer 10162346
   [junit4]   2> 2058511 T7041 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1375691271178\]
   [junit4]   2> 2058512 T7041 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 2058512 T7041 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 2058512 T7041 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 2058513 T7041 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 2058513 T7041 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 2058513 T7041 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 2058514 T7041 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 2058514 T7041 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 2058514 T7041 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 2058515 T7041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 2058525 T7041 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:58928/solr
   [junit4]   2> 2058526 T7041 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2058528 T7041 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2058538 T7061 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d456eb name:ZooKeeperConnection Watcher:127.0.0.1:58928 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2058539 T7041 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2058542 T7041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 2058549 T7041 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2058552 T7063 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19a4d15 name:ZooKeeperConnection Watcher:127.0.0.1:58928/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2058553 T7041 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2058555 T7041 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 2058562 T7041 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 2058567 T7041 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 2058571 T7041 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58935_
   [junit4]   2> 2058573 T7041 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58935_
   [junit4]   2> 2058578 T7041 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 2058588 T7041 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 2058593 T7041 oasc.Overseer.start Overseer (id=90157303126556675-127.0.0.1:58935_-n_0000000000) starting
   [junit4]   2> 2058602 T7041 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 2058611 T7065 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 2058611 T7041 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 2058615 T7041 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 2058619 T7041 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2058623 T7064 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 2058626 T7066 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 2058627 T7066 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2058629 T7066 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 2060128 T7064 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2060130 T7064 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:58935_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58935"}
   [junit4]   2> 2060130 T7064 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 2060130 T7064 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 2060144 T7063 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> 2060629 T7066 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 2060629 T7066 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1375691271178\collection1
   [junit4]   2> 2060629 T7066 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 2060631 T7066 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 2060631 T7066 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 2060633 T7066 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1375691271178\collection1\'
   [junit4]   2> 2060634 T7066 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1375691271178/collection1/lib/classes/' to classloader
   [junit4]   2> 2060635 T7066 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1375691271178/collection1/lib/README' to classloader
   [junit4]   2> 2060667 T7066 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 2060682 T7066 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 2060685 T7066 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 2060691 T7066 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 2060807 T7066 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2060809 T7066 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2060810 T7066 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2060814 T7066 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2060843 T7066 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 2060844 T7066 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1375691271178\collection1\, dataDir=.\org.apache.solr.cloud.ShardSplitTest-1375691270839/control/data\
   [junit4]   2> 2060844 T7066 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1f5ce76
   [junit4]   2> 2060844 T7066 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1375691270839/control/data\
   [junit4]   2> 2060844 T7066 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardSplitTest-1375691270839/control/data\index/
   [junit4]   2> 2060844 T7066 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ShardSplitTest-1375691270839\control\data\index' doesn't exist. Creating new index...
   [junit4]   2> 2060846 T7066 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1375691270839/control/data\index
   [junit4]   2> 2060851 T7066 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2441f9 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4a2442),segFN=segments_1,generation=1}
   [junit4]   2> 2060851 T7066 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2060856 T7066 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 2060856 T7066 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2060857 T7066 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2060858 T7066 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 2060858 T7066 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 2060858 T7066 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 2060859 T7066 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 2060859 T7066 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 2060859 T7066 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 2060867 T7066 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2060870 T7066 oass.SolrIndexSearcher.<init> Opening Searcher@153dc7b main
   [junit4]   2> 2060874 T7066 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 2060875 T7066 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 2060878 T7067 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@153dc7b main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 2060878 T7066 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 2060878 T7066 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58935 collection:control_collection shard:shard1
   [junit4]   2> 2060879 T7066 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 2060888 T7066 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 2060906 T7066 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 2060911 T7066 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 2060911 T7066 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 2060911 T7066 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58935/collection1/
   [junit4]   2> 2060911 T7066 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 2060911 T7066 oasc.SyncStrategy.syncToMe http://127.0.0.1:58935/collection1/ has no replicas
   [junit4]   2> 2060911 T7066 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58935/collection1/ shard1
   [junit4]   2> 2060912 T7066 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 2061652 T7064 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2061670 T7063 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> 2061686 T7066 oasc.ZkController.register We are http://127.0.0.1:58935/collection1/ and leader is http://127.0.0.1:58935/collection1/
   [junit4]   2> 2061686 T7066 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58935
   [junit4]   2> 2061686 T7066 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 2061686 T7066 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 2061686 T7066 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2061690 T7066 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2061691 T7041 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 2061692 T7041 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 2061692 T7041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 2061698 T7041 oascsi.HttpClientUtil.createClient Creating new http client, config:
   [junit4]   2> 2061701 T7041 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2061705 T7070 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11b1b4 name:ZooKeeperConnection Watcher:127.0.0.1:58928/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2061705 T7041 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2061707 T7041 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2061711 T7041 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 2062169 T7041 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 2062174 T7041 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58947
   [junit4]   2> 2062175 T7041 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 2062175 T7041 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2062175 T7041 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1375691274915
   [junit4]   2> 2062176 T7041 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1375691274915\'
   [junit4]   2> 2062207 T7041 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1375691274915\solr.xml
   [junit4]   2> 2062228 T7041 oasc.CoreContainer.<init> New CoreContainer 32805532
   [junit4]   2> 2062229 T7041 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1375691274915\]
   [junit4]   2> 2062229 T7041 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 2062229 T7041 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 2062230 T7041 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 2062230 T7041 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 2062230 T7041 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 2062231 T7041 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 2062231 T7041 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 2062231 T7041 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 2062232 T7041 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 2062232 T7041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 2062239 T7041 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:58928/solr
   [junit4]   2> 2062240 T7041 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2062242 T7041 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2062258 T7081 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@188938e name:ZooKeeperConnection Watcher:127.0.0.1:58928 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2062259 T7041 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2062263 T7041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 2062269 T7041 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2062273 T7083 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@199562 name:ZooKeeperConnection Watcher:127.0.0.1:58928/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2062273 T7041 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2062281 T7041 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2063181 T7064 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2063185 T7064 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:58935_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58935"}
   [junit4]   2> 2063196 T7070 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> 2063197 T7063 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> 2063196 T7083 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> 2063284 T7041 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58947_
   [junit4]   2> 2063287 T7041 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58947_
   [junit4]   2> 2063291 T7063 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
   [junit4]   2> 2063292 T7083 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 2063292 T7083 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 2063293 T7070 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 2063293 T7070 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 2063295 T7063 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 2063303 T7084 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 2063303 T7084 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2063306 T7084 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 2064704 T7064 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2064706 T7064 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:58947_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58947"}
   [junit4]   2> 2064706 T7064 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 2064706 T7064 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 2064719 T7070 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> 2064720 T7063 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> 2064720 T7083 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> 2065306 T7084 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 2065306 T7084 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1375691274915\collection1
   [junit4]   2> 2065306 T7084 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 2065309 T7084 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 2065309 T7084 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 2065312 T7084 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1375691274915\collection1\'
   [junit4]   2> 2065313 T7084 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1375691274915/collection1/lib/classes/' to classloader
   [junit4]   2> 2065314 T7084 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1375691274915/collection1/lib/README' to classloader
   [junit4]   2> 2065339 T7084 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 2065346 T7084 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 2065349 T7084 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 2065355 T7084 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 2065476 T7084 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2065478 T7084 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2065479 T7084 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2065483 T7084 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2065516 T7084 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 2065517 T7084 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1375691274915\collection1\, dataDir=.\org.apache.solr.cloud.ShardSplitTest-1375691270839/jetty1\
   [junit4]   2> 2065517 T7084 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1f5ce76
   [junit4]   2> 2065518 T7084 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1375691270839/jetty1\
   [junit4]   2> 2065518 T7084 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardSplitTest-1375691270839/jetty1\index/
   [junit4]   2> 2065518 T7084 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ShardSplitTest-1375691270839\jetty1\index' doesn't exist. Creating new index...
   [junit4]   2> 2065518 T7084 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1375691270839/jetty1\index
   [junit4]   2> 2065522 T7084 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1db3326 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1676b76),segFN=segments_1,generation=1}
   [junit4]   2> 2065522 T7084 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2065528 T7084 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 2065528 T7084 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2065529 T7084 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2065530 T7084 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 2065531 T7084 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 2065531 T7084 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 2065531 T7084 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 2065531 T7084 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 2065532 T7084 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 2065543 T7084 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2065545 T7084 oass.SolrIndexSearcher.<init> Opening Searcher@14482f main
   [junit4]   2> 2065547 T7084 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 2065547 T7084 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 2065561 T7085 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@14482f main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 2065564 T7084 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 2065564 T7084 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58947 collection:collection1 shard:shard1
   [junit4]   2> 2065565 T7084 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 2065575 T7084 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 2065596 T7084 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 2065602 T7084 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 2065602 T7084 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 2065602 T7084 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58947/collection1/
   [junit4]   2> 2065602 T7084 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 2065602 T7084 oasc.SyncStrategy.syncToMe http://127.0.0.1:58947/collection1/ has no replicas
   [junit4]   2> 2065602 T7084 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58947/collection1/ shard1
   [junit4]   2> 2065602 T7084 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 2066231 T7064 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2066249 T7070 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> 2066249 T7083 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> 2066250 T7063 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> 2066279 T7084 oasc.ZkController.register We are http://127.0.0.1:58947/collection1/ and leader is http://127.0.0.1:58947/collection1/
   [junit4]   2> 2066279 T7084 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58947
   [junit4]   2> 2066279 T7084 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 2066280 T7084 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 2066280 T7084 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2066282 T7084 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2066284 T7041 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 2066285 T7041 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 2066285 T7041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 2066737 T7041 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 2066741 T7041 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58956
   [junit4]   2> 2066741 T7041 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 2066742 T7041 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2066742 T7041 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1375691279494
   [junit4]   2> 2066742 T7041 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1375691279494\'
   [junit4]   2> 2066774 T7041 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1375691279494\solr.xml
   [junit4]   2> 2066785 T7041 oasc.CoreContainer.<init> New CoreContainer 23411144
   [junit4]   2> 2066786 T7041 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1375691279494\]
   [junit4]   2> 2066787 T7041 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 2066787 T7041 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 2066787 T7041 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 2066788 T7041 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 2066788 T7041 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 2066788 T7041 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 2066789 T7041 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 2066789 T7041 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 2066789 T7041 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 2066790 T7041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 2066798 T7041 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:58928/solr
   [junit4]   2> 2066798 T7041 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2066800 T7041 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2066816 T7097 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2f9a13 name:ZooKeeperConnection Watcher:127.0.0.1:58928 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2066816 T7041 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2066820 T7041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 2066820 T7043 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1404d96eac40007, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:724)
   [junit4]   2> 
   [junit4]   2> 2066830 T7041 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2066834 T7099 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9a83ed name:ZooKeeperConnection Watcher:127.0.0.1:58928/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2066835 T7041 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2066843 T7041 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2067763 T7064 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2067765 T7064 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:58947_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58947"}
   [junit4]   2> 2067781 T7083 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> 2067781 T7063 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> 2067781 T7070 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> 2067783 T7099 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> 2067848 T7041 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58956_
   [junit4]   2> 2067851 T7041 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58956_
   [junit4]   2> 2067855 T7063 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 2067855 T7099 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 2067856 T7070 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 2067857 T7070 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 2067858 T7083 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 2067858 T7083 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 2067862 T7099 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 2067862 T7063 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 2067869 T7100 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 2067869 T7100 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2067872 T7100 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 2069292 T7064 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2069294 T7064 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:58956_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58956"}
   [junit4]   2> 2069294 T7064 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 2069294 T7064 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 2069307 T7070 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> 2069308 T7099 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> 2069308 T7083 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> 2069309 T7063 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> 2069872 T7100 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 2069872 T7100 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1375691279494\collection1
   [junit4]   2> 2069872 T7100 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 2069873 T7100 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 2069873 T7100 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 2069875 T7100 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1375691279494\collection1\'
   [junit4]   2> 2069877 T7100 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1375691279494/collection1/lib/classes/' to classloader
   [junit4]   2> 2069878 T7100 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1375691279494/collection1/lib/README' to classloader
   [junit4]   2> 2069906 T7100 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 2069925 T7100 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 2069927 T7100 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 2069934 T7100 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 2070051 T7100 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2070052 T7100 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2070053 T7100 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2070057 T7100 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2070088 T7100 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 2070089 T7100 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1375691279494\collection1\, dataDir=.\org.apache.solr.cloud.ShardSplitTest-1375691270839/jetty2\
   [junit4]   2> 2070089 T7100 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1f5ce76
   [junit4]   2> 2070090 T7100 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1375691270839/jetty2\
   [junit4]   2> 2070090 T7100 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardSplitTest-1375691270839/jetty2\index/
   [junit4]   2> 2070090 T7100 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ShardSplitTest-1375691270839\jetty2\index' doesn't exist. Creating new index...
   [junit4]   2> 2070090 T7100 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1375691270839/jetty2\index
   [junit4]   2> 2070095 T7100 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@c474e5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@11ad757),segFN=segments_1,generation=1}
   [junit4]   2> 2070095 T7100 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2070100 T7100 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 2070101 T7100 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2070102 T7100 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2070103 T7100 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 2070103 T7100 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 2070103 T7100 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 2070104 T7100 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 2070104 T7100 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 2070104 T7100 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 2070113 T7100 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2070114 T7100 oass.SolrIndexSearcher.<init> Opening Searcher@1d031f4 main
   [junit4]   2> 2070115 T7100 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 2070115 T7100 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 2070121 T7101 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1d031f4 main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 2070123 T7100 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 2070123 T7100 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58956 collection:collection1 shard:shard2
   [junit4]   2> 2070123 T7100 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 2070133 T7100 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 2070149 T7100 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 2070154 T7100 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 2070154 T7100 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 2070154 T7100 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58956/collection1/
   [junit4]   2> 2070154 T7100 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 2070154 T7100 oasc.SyncStrategy.syncToMe http://127.0.0.1:58956/collection1/ has no replicas
   [junit4]   2> 2070154 T7100 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58956/collection1/ shard2
   [junit4]   2> 2070155 T7100 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 2070819 T7064 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2070838 T7083 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> 2070838 T7070 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> 2070839 T7063 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> 2070839 T7099 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> 2070875 T7100 oasc.ZkController.register We are http://127.0.0.1:58956/collection1/ and leader is http://127.0.0.1:58956/collection1/
   [junit4]   2> 2070875 T7100 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58956
   [junit4]   2> 2070875 T7100 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 2070875 T7100 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 2070875 T7100 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2070880 T7100 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2070882 T7041 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 2070882 T7041 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 2070883 T7041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 2071345 T7041 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 2071350 T7041 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58965
   [junit4]   2> 2071351 T7041 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 2071351 T7041 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2071352 T7041 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1375691284092
   [junit4]   2> 2071352 T7041 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1375691284092\'
   [junit4]   2> 2071384 T7041 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1375691284092\solr.xml
   [junit4]   2> 2071396 T7041 oasc.CoreContainer.<init> New CoreContainer 17599410
   [junit4]   2> 2071397 T7041 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1375691284092\]
   [junit4]   2> 2071398 T7041 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 2071398 T7041 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 2071398 T7041 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 2071399 T7041 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 2071399 T7041 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 2071400 T7041 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 2071400 T7041 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 2071401 T7041 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 2071401 T7041 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 2071401 T7041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 2071410 T7041 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:58928/solr
   [junit4]   2> 2071411 T7041 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2071415 T7041 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2071455 T7113 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c30fc name:ZooKeeperConnection Watcher:127.0.0.1:58928 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2071455 T7041 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2071466 T7041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 2071473 T7041 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2071478 T7115 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b4c8ed name:ZooKeeperConnection Watcher:127.0.0.1:58928/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2071478 T7041 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2071485 T7041 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2072350 T7064 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2072352 T7064 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:58956_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58956"}
   [junit4]   2> 2072364 T7115 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> 2072364 T7099 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> 2072364 T7083 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> 2072365 T7063 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> 2072364 T7070 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> 2072489 T7041 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58965_
   [junit4]   2> 2072492 T7041 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58965_
   [junit4]   2> 2072496 T7099 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 2072497 T7063 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 2072498 T7115 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 2072498 T7115 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 2072499 T7083 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 2072499 T7083 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 2072501 T7070 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 2072503 T7070 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 2072503 T7099 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 2072504 T7063 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 2072512 T7116 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 2072512 T7116 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2072516 T7116 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 2073876 T7064 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2073878 T7064 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node3",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:58965_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58965"}
   [junit4]   2> 2073878 T7064 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 2073878 T7064 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 2073892 T7115 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 2073893 T7083 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 2073893 T7063 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 2073892 T7070 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 2073894 T7099 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 2074516 T7116 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 2074516 T7116 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1375691284092\collection1
   [junit4]   2> 2074516 T7116 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 2074517 T7116 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 2074517 T7116 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 2074519 T7116 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1375691284092\collection1\'
   [junit4]   2> 2074521 T7116 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1375691284092/collection1/lib/classes/' to classloader
   [junit4]   2> 2074533 T7116 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1375691284092/collection1/lib/README' to classloader
   [junit4]   2> 2074571 T7116 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_45
   [junit4]   2> 2074582 T7116 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 2074585 T7116 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 2074596 T7116 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 2074734 T7116 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2074736 T7116 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2074738 T7116 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2074743 T7116 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2074791 T7116 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 2074793 T7116 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1375691284092\collection1\, dataDir=.\org.apache.solr.cloud.ShardSplitTest-1375691270839/jetty3\
   [junit4]   2> 2074793 T7116 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1f5ce76
   [junit4]   2> 2074794 T7116 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1375691270839/jetty3\
   [junit4]   2> 2074794 T7116 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardSplitTest-1375691270839/jetty3\index/
   [junit4]   2> 2074794 T7116 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ShardSplitTest-1375691270839\jetty3\index' doesn't exist. Creating new index...
   [junit4]   2> 2074795 T7116 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1375691270839/jetty3\index
   [junit4]   2> 2074801 T7116 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@18cc35e lockFactory=org.apache.lucene.store.NativeFSLockFactory@887ac6),segFN=segments_1,generation=1}
   [junit4]   2> 2074802 T7116 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2074809 T7116 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 2074810 T7116 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2074811 T7116 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2074812 T7116 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 2074813 T7116 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 2074813 T7116 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 2074813 T7116 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 2074815 T7116 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 2074815 T7116 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 2074825 T7116 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2074827 T7116 oass.SolrIndexSearcher.<init> Opening Searcher@1d049ba main
   [junit4]   2> 2074830 T7116 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 2074830 T7116 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 2074837 T7117 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1d049ba main{StandardDirectoryReader(segments_1:1)}
   [junit4]   2> 2074839 T7116 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 2074839 T7116 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58965 collection:collection1 shard:shard1
   [junit4]   2> 2074839 T7116 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
   [junit4]   2> 2074863 T7116 oasc.ZkController.register We are http://127.0.0.1:58965/collection1/ and leader is http://127.0.0.1:58947/collection1/
   [junit4]   2> 2074863 T7116 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58965
   [junit4]   2> 2074863 T7116 oasc.ZkController.checkRecovery Core needs to recover:collection1
   [junit4]   2> 2074864 T7116 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
   [junit4]   2> ASYNC  NEW_CORE C8172 name=collection1 org.apache.solr.core.SolrCore@102cdbd url=http://127.0.0.1:58965/collection1 node=127.0.0.1:58965_ C8172_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, node_name=127.0.0.1:58965_, base_url=http://127.0.0.1:58965}
   [junit4]   2> 2074864 T7118 C8172 P58965 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
   [junit4]   2> 2074866 T7118 C8172 P58965 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
   [junit4]   2> 2074866 T7116 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2074866 T7118 C8172 P58965 oasc.ZkController.publish publishing core=collection1 state=recovering
   [junit4]   2> 2074867 T7118 C8172 P58965 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2074868 T7041 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 2074869 T7041 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 2074870 T7118 C8172 P58965 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 2074870 T7041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
   [junit4]   2> 2074878 T7076 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
   [junit4]   2> 2075408 T7064 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2075410 T7064 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node3",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"recovering",
   [junit4]   2> 	  "shard_state":"active",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard_range":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:58965_",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:58965"}
   [junit4]   2> 2075418 T7041 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 2075467 T7041 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58975
   [junit4]   2> 2075468 T7041 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 2075468 T7041 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2075469 T7041 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty4-1375691288082
   [junit4]   2> 2075469 T7041 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty4-1375691288082\'
   [junit4]   2> 2075491 T7115 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 2075491 T7083 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 2075492 T7063 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 2075492 T7099 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 2075493 T7070 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 2075520 T7041 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty4-1375691288082\solr.xml
   [junit4]   2> 2075536 T7041 oasc.CoreContainer.<init> New CoreContainer 27576596
   [junit4]   2> 2075537 T7041 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty4-1375691288082\]
   [junit4]   2> 2075538 T7041 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
   [junit4]   2> 2075538 T7041 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 2075539 T7041 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 2075540 T7041 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 2075541 T7041 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 2075541 T7041 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 2075541 T7041 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 2075541 T7041 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 2075542 T7041 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 2075543 T7041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
   [junit4]   2> 2075555 T7041 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:58928/solr
   [junit4]   2> 2075556 T7041 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2075558 T7041 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2075565 T7130 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@662863 name:ZooKeeperConnection Watcher:127.0.0.1:58928 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2075565 T7041 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2075569 T7041 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
   [junit4]   2> 2075578 T7041 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2075594 T7132 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17c9f6c name:ZooKeeperConnection Watcher:127.0.0.1:58928/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2075595 T7041 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2075606 T7041 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2075878 T7076 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
   [junit4]   2> 2075878 T7076 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=core_node3&state=recovering&nodeName=127.0.0.1:58965_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1000 
   [junit4]   2> 2076614 T7041 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58975_
   [junit4]   2> 2076616 T7041 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58975_
   [junit4]   2> 2076621 T7063 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 2076621 T7099 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 2076622 T7070 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 2076622 T7070 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 2076623 T7132 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 2076623 T7115 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 2076623 T7115 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 2076624 T7083 oascc.ZkStateReader$3.process Updating live nodes... (5)
   [junit4]   2> 2076624 T7083 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
   [junit4]   2> 2076629 T7099 oascc.ZkStateReader$3.process Updating live nodes... (5)

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

157303126556680-127.0.0.1:58956_-n_0000000002 (0)
   [junit4]   1>     /solr/overseer_elect/election/90157303126556678-127.0.0.1:58947_-n_0000000001 (0)
   [junit4]   1>     /solr/overseer_elect/election/90157303126556675-127.0.0.1:58935_-n_0000000000 (0)
   [junit4]   1>     /solr/overseer_elect/election/90157303126556684-127.0.0.1:58975_-n_0000000004 (0)
   [junit4]   1>    /solr/overseer_elect/leader (0)
   [junit4]   1>    DATA:
   [junit4]   1>        {"id":"90157303126556675-127.0.0.1:58935_-n_0000000000"}
   [junit4]   1>  /zookeeper (1)
   [junit4]   1>  DATA:
   [junit4]   1>      
   [junit4]   1> 
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=ShardSplitTest -Dtests.method=testDistribSearch -Dtests.seed=185A3CF194F7C1F7 -Dtests.slow=true -Dtests.locale=sr_RS -Dtests.timezone=Etc/GMT-14 -Dtests.file.encoding=Cp1252
   [junit4] FAILURE 67.1s | ShardSplitTest.testDistribSearch <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: Wrong doc count on shard1_0 expected:<83> but was:<84>
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([185A3CF194F7C1F7:99BCB2E9E3A8A1CB]:0)
   [junit4]    > 	at org.apache.solr.cloud.ShardSplitTest.checkDocCountsAndShardStates(ShardSplitTest.java:226)
   [junit4]    > 	at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:173)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:724)
   [junit4]   2> 2124709 T7041 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 67083 T7040 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
   [junit4]   2> NOTE: test params are: codec=Lucene42: {id=PostingsFormat(name=NestedPulsing), _version_=PostingsFormat(name=Memory doPackFST= true), n_ti=PostingsFormat(name=Direct)}, docValues:{}, sim=DefaultSimilarity, locale=sr_RS, timezone=Etc/GMT-14
   [junit4]   2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.8.0-ea (32-bit)/cpus=2,threads=1,free=59676536,total=212623360
   [junit4]   2> NOTE: All tests run in this JVM: [SolrCoreTest, CircularListTest, SchemaVersionSpecificBehaviorTest, ShowFileRequestHandlerTest, TestPhraseSuggestions, TestMultiCoreConfBootstrap, CoreAdminHandlerTest, PeerSyncTest, TestLuceneMatchVersion, URLClassifyProcessorTest, TestSolrCoreProperties, TestSolrXml, ShardRoutingCustomTest, DeleteShardTest, TestClassNameShortening, TestFieldTypeCollectionResource, TestPartialUpdateDeduplication, FileUtilsTest, MoreLikeThisHandlerTest, BasicDistributedZk2Test, PingRequestHandlerTest, TestDynamicFieldCollectionResource, TestCSVResponseWriter, TestUtils, TestIBSimilarityFactory, TestRandomDVFaceting, AddSchemaFieldsUpdateProcessorFactoryTest, TestSchemaResource, DocValuesTest, TestSchemaVersionResource, XmlUpdateRequestHandlerTest, LegacyHTMLStripCharFilterTest, TestSolrQueryParser, TestSchemaNameResource, TestBinaryResponseWriter, IndexReaderFactoryTest, TestFastLRUCache, TestFunctionQuery, NoCacheHeaderTest, DateMathParserTest, OverseerTest, AlternateDirectoryTest, TestFoldingMultitermQuery, TestPseudoReturnFields, SampleTest, CoreContainerCoreInitFailuresTest, TermVectorComponentTest, StatsComponentTest, TestInfoStreamLogging, PreAnalyzedFieldTest, TestConfig, StandardRequestHandlerTest, SuggesterTSTTest, PathHierarchyTokenizerFactoryTest, TermsComponentTest, ZkSolrClientTest, TestAnalyzedSuggestions, TestSolrJ, TestPostingsSolrHighlighter, SolrPluginUtilsTest, TestComponentsName, XsltUpdateRequestHandlerTest, TestZkChroot, TestPropInjectDefaults, TestNumberUtils, TestFieldCollectionResource, CoreMergeIndexesAdminHandlerTest, HdfsLockFactoryTest, TestRandomFaceting, BadIndexSchemaTest, TestCSVLoader, TestJmxMonitoredMap, SpellPossibilityIteratorTest, LeaderElectionTest, BlockCacheTest, TestSolrQueryParserResource, TestDynamicFieldResource, SolrRequestParserTest, TestMergePolicyConfig, CachingDirectoryFactoryTest, BadCopyFieldTest, RecoveryZkTest, QueryResultKeyTest, TestManagedSchemaFieldResource, TestRandomMergePolicy, PolyFieldTest, StatelessScriptUpdateProcessorFactoryTest, TestOmitPositions, SearchHandlerTest, SliceStateUpdateTest, TestQuerySenderListener, TestCollationField, HdfsBasicDistributedZk2Test, WordBreakSolrSpellCheckerTest, UUIDFieldTest, DistributedSpellCheckComponentTest, ChaosMonkeySafeLeaderTest, TestCodecSupport, TestRecoveryHdfs, IndexSchemaTest, CopyFieldTest, UniqFieldsUpdateProcessorFactoryTest, BinaryUpdateRequestHandlerTest, ZkCLITest, TestTrie, TestReversedWildcardFilterFactory, ClusterStateUpdateTest, RequestHandlersTest, TestIndexingPerformance, TestMaxScoreQueryParser, ParsingFieldUpdateProcessorsTest, UpdateParamsTest, MBeansHandlerTest, SolrCoreCheckLockOnStartupTest, DistanceFunctionTest, TestSort, TestRangeQuery, TestStressVersions, TestElisionMultitermQuery, IndexSchemaRuntimeFieldTest, SimpleFacetsTest, SynonymTokenizerTest, StressHdfsTest, HdfsCollectionsAPIDistributedZkTest, ResponseLogComponentTest, TestGroupingSearch, TestCoreContainer, SolrIndexSplitterTest, CurrencyFieldXmlFileTest, TestSolrQueryParserDefaultOperatorResource, TestCoreDiscovery, PrimitiveFieldTypeTest, TestShardHandlerFactory, CacheHeaderTest, TestJmxIntegration, DistributedTermsComponentTest, SOLR749Test, DefaultValueUpdateProcessorTest, TestSolr4Spatial, HdfsUnloadDistributedZkTest, AliasIntegrationTest, OutputWriterTest, TestManagedSchema, FileBasedSpellCheckerTest, TestBinaryField, TestSystemIdResolver, SuggesterFSTTest, DocumentAnalysisRequestHandlerTest, SystemInfoHandlerTest, InfoHandlerTest, TestWriterPerf, TestAddFieldRealTimeGet, BasicDistributedZkTest, UnloadDistributedZkTest, SyncSliceTest, OpenCloseCoreStressTest, LeaderElectionIntegrationTest, ShardRoutingTest, BasicZkTest, FullSolrCloudDistribCmdsTest, TestReplicationHandler, TestDistributedSearch, AutoCommitTest, TestDistributedGrouping, TestFaceting, TestRecovery, TestHashPartitioner, TermVectorComponentDistributedTest, ZkControllerTest, TestRealTimeGet, TestStressReorder, TestJoin, TestReload, HardAutoCommitTest, SpellCheckComponentTest, SolrCmdDistributorTest, QueryElevationComponentTest, ConvertedLegacyTest, TestFiltering, BasicFunctionalityTest, TestLazyCores, DirectUpdateHandlerTest, TestBadConfig, OverseerCollectionProcessorTest, TestIndexSearcher, HighlighterTest, SoftAutoCommitTest, CurrencyFieldOpenExchangeTest, DistributedQueryElevationComponentTest, SimplePostToolTest, AnalysisAfterCoreReloadTest, SignatureUpdateProcessorFactoryTest, TestExtendedDismaxParser, SpellCheckCollatorTest, SuggesterTest, TestStressLucene, SpatialFilterTest, SuggesterWFSTTest, TestUpdate, FieldMutatingUpdateProcessorTest, TestAtomicUpdateErrorCases, TestWordDelimiterFilterFactory, QueryEqualityTest, DirectUpdateHandlerOptimizeTest, SortByFunctionTest, TestRemoteStreaming, DocValuesMultiTest, TestSolrDeletionPolicy1, SolrInfoMBeanTest, DebugComponentTest, IndexBasedSpellCheckerTest, TestSurroundQueryParser, LukeRequestHandlerTest, DisMaxRequestHandlerTest, TestQueryUtils, DirectSolrSpellCheckerTest, TestQueryTypes, DocumentBuilderTest, TestValueSourceCache, RequiredFieldsTest, FieldAnalysisRequestHandlerTest, TestArbitraryIndexDir, FastVectorHighlighterTest, LoggingHandlerTest, RegexBoostProcessorTest, ReturnFieldsTest, UpdateRequestProcessorFactoryTest, JSONWriterTest, QueryParsingTest, JsonLoaderTest, TestPHPSerializedResponseWriter, CSVRequestHandlerTest, TestLFUCache, HighlighterConfigTest, TestPropInject, TestSolrIndexConfig, TestQuerySenderNoQuery, SolrIndexConfigTest, BadComponentTest, TestStressRecovery, TestSolrDeletionPolicy2, MultiTermTest, TestDocSet, TestSearchPerf, NumericFieldsTest, MinimalSchemaTest, TestFuzzyAnalyzedSuggestions, ExternalFileFieldSortTest, DirectSolrConnectionTest, NotRequiredUniqueKeyTest, TestCharFilters, TestXIncludeConfig, EchoParamsTest, TestSweetSpotSimilarityFactory, TestDFRSimilarityFactory, TestPerFieldSimilarity, TestLMDirichletSimilarityFactory, TestLMJelinekMercerSimilarityFactory, TestBM25SimilarityFactory, TestDefaultSimilarityFactory, TestFastWriter, TestPluginEnable, TimeZoneUtilsTest, ResourceLoaderTest, TestFastOutputStream, ScriptEngineTest, OpenExchangeRatesOrgProviderTest, PluginInfoTest, ChaosMonkeyNothingIsSafeTest, TestSolrXMLSerializer, PrimUtilsTest, TestSuggestSpellingConverter, DateFieldTest, SpellingQueryConverterTest, DOMUtilTest, RAMDirectoryFactoryTest, ClusterStateTest, TestLRUCache, TestDocumentBuilder, ZkNodePropsTest, SliceStateTest, TestRTGBase, SolrTestCaseJ4Test, TestCollationKeyRangeQueries, AssignTest, ShardSplitTest]
   [junit4] Completed in 68.20s, 1 test, 1 failure <<< FAILURES!

[...truncated 69 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:395: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:375: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build.xml:181: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\common-build.xml:449: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1233: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:876: There were test failures: 321 suites, 1351 tests, 1 failure, 41 ignored (11 assumptions)

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