You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/03/15 03:57:13 UTC

[JENKINS] Lucene-Solr-trunk-Windows (64bit/jdk1.7.0_60-ea-b07) - Build # 3862 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/3862/
Java: 64bit/jdk1.7.0_60-ea-b07 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC

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

Error Message:
Wrong doc count on shard1_0 expected:<115> but was:<116>

Stack Trace:
java.lang.AssertionError: Wrong doc count on shard1_0 expected:<115> but was:<116>
	at __randomizedtesting.SeedInfo.seed([21981B5EE79E5D7:83FF0FAD992685EB]: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:465)
	at org.apache.solr.cloud.ShardSplitTest.splitByUniqueKeyTest(ShardSplitTest.java:237)
	at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:101)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:870)
	at sun.reflect.GeneratedMethodAccessor44.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1617)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
	at java.lang.Thread.run(Thread.java:744)




Build Log:
[...truncated 11052 lines...]
   [junit4] Suite: org.apache.solr.cloud.ShardSplitTest
   [junit4]   2> 2988218 T10775 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /vagf/ur
   [junit4]   2> 2988225 T10775 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-ShardSplitTest-1394851785140
   [junit4]   2> 2988229 T10775 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 2988231 T10776 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 2988339 T10775 oasc.ZkTestServer.run start zk server on port:53131
   [junit4]   2> 2988340 T10775 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2988348 T10782 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@343a2424 name:ZooKeeperConnection Watcher:127.0.0.1:53131 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2988349 T10775 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2988349 T10775 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 2988357 T10777 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144c3a529c20000, 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:744)
   [junit4]   2> 
   [junit4]   2> 2988360 T10775 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2988364 T10784 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5c571b87 name:ZooKeeperConnection Watcher:127.0.0.1:53131/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2988364 T10775 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2988364 T10775 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 2988371 T10775 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 2988377 T10775 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 2988382 T10775 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 2988388 T10775 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 2988389 T10775 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 2988398 T10775 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\schema15.xml to /configs/conf1/schema.xml
   [junit4]   2> 2988398 T10775 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 2988412 T10775 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 2988412 T10775 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 2988419 T10775 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 2988420 T10775 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 2988425 T10775 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 2988425 T10775 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 2988430 T10775 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 2988431 T10775 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 2988438 T10775 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 2988439 T10775 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 2988443 T10775 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 2988444 T10775 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 2988449 T10775 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 2988450 T10775 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 2988454 T10775 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 2988455 T10775 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 2988460 T10775 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 2988461 T10775 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 2988467 T10777 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144c3a529c20001, 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:744)
   [junit4]   2> 
   [junit4]   2> 2990446 T10775 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 2990458 T10775 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53138
   [junit4]   2> 2990460 T10775 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 2990460 T10775 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2990461 T10775 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1394851785380
   [junit4]   2> 2990461 T10775 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1394851785380\'
   [junit4]   2> 2990507 T10775 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1394851785380\solr.xml
   [junit4]   2> 2990571 T10775 oasc.CoreContainer.<init> New CoreContainer 759748975
   [junit4]   2> 2990572 T10775 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1394851785380\]
   [junit4]   2> 2990574 T10775 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 2990574 T10775 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 2990575 T10775 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 2990575 T10775 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 2990575 T10775 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 2990575 T10775 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 2990576 T10775 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 2990576 T10775 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 2990576 T10775 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 2990582 T10775 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 2990582 T10775 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 2990583 T10775 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 2990583 T10775 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53131/solr
   [junit4]   2> 2990583 T10775 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2990586 T10775 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2990593 T10795 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9bb1da3 name:ZooKeeperConnection Watcher:127.0.0.1:53131 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2990594 T10775 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2990597 T10777 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144c3a529c20002, 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:744)
   [junit4]   2> 
   [junit4]   2> 2990598 T10775 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2990603 T10797 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@71c4429 name:ZooKeeperConnection Watcher:127.0.0.1:53131/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2990603 T10775 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2990605 T10775 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 2990611 T10775 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 2990626 T10775 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 2990633 T10775 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 2990640 T10775 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 2990646 T10775 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 2990650 T10775 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53138_vagf%2Fur
   [junit4]   2> 2990652 T10775 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53138_vagf%2Fur
   [junit4]   2> 2990658 T10775 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 2990662 T10775 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 2990670 T10775 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:53138_vagf%2Fur
   [junit4]   2> 2990670 T10775 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 2990674 T10775 oasc.Overseer.start Overseer (id=91413006591852547-127.0.0.1:53138_vagf%2Fur-n_0000000000) starting
   [junit4]   2> 2990680 T10775 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 2990699 T10799 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 2990701 T10775 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 2990701 T10799 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 2990705 T10775 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 2990708 T10775 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2990714 T10798 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 2990722 T10800 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 2990722 T10800 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2990724 T10800 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 2990724 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2990726 T10798 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2990727 T10798 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:53138/vagf/ur",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53138_vagf%2Fur",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 2990729 T10798 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 2990729 T10798 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 2990733 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2990734 T10797 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> 2991910 T10800 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 2991910 T10800 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1394851785380\collection1
   [junit4]   2> 2991911 T10800 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 2991913 T10800 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 2991913 T10800 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 2991918 T10800 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 2991919 T10800 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1394851785380\collection1\'
   [junit4]   2> 2991927 T10800 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1394851785380/collection1/lib/.svn/' to classloader
   [junit4]   2> 2991931 T10800 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1394851785380/collection1/lib/classes/' to classloader
   [junit4]   2> 2991932 T10800 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1394851785380/collection1/lib/README' to classloader
   [junit4]   2> 2992002 T10800 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 2992073 T10800 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 2992078 T10800 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 2992091 T10800 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 2992499 T10800 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2992501 T10800 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2992502 T10800 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2992509 T10800 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2992545 T10800 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 2992546 T10800 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1394851785380\collection1\, dataDir=.\org.apache.solr.cloud.ShardSplitTest-1394851785138/control/data\
   [junit4]   2> 2992546 T10800 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2006650b
   [junit4]   2> 2992547 T10800 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1394851785138/control/data\
   [junit4]   2> 2992547 T10800 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardSplitTest-1394851785138/control/data\index/
   [junit4]   2> 2992547 T10800 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ShardSplitTest-1394851785138\control\data\index' doesn't exist. Creating new index...
   [junit4]   2> 2992547 T10800 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1394851785138/control/data\index
   [junit4]   2> 2992548 T10800 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=389407684, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 2992550 T10800 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@634ee69e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@16cf51cd),segFN=segments_1,generation=1}
   [junit4]   2> 2992550 T10800 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2992553 T10800 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 2992554 T10800 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 2992554 T10800 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 2992554 T10800 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2992554 T10800 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2992555 T10800 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 2992555 T10800 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2992555 T10800 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2992557 T10800 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 2992557 T10800 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 2992557 T10800 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 2992558 T10800 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 2992558 T10800 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 2992558 T10800 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 2992559 T10800 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 2992559 T10800 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 2992560 T10800 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 2992570 T10800 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2992579 T10800 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 2992579 T10800 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 2992580 T10800 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=18, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.18867959167681914]
   [junit4]   2> 2992580 T10800 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@634ee69e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@16cf51cd),segFN=segments_1,generation=1}
   [junit4]   2> 2992580 T10800 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2992581 T10800 oass.SolrIndexSearcher.<init> Opening Searcher@4e5d9ba9[collection1] main
   [junit4]   2> 2992581 T10800 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 2992583 T10800 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 2992583 T10800 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 2992584 T10800 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 2992584 T10800 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 2992584 T10800 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2992585 T10800 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 2992585 T10800 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2992585 T10800 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 2992587 T10800 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 2992589 T10801 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4e5d9ba9[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 2992590 T10800 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 2992591 T10775 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 2992591 T10804 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53138/vagf/ur collection:control_collection shard:shard1
   [junit4]   2> 2992591 T10775 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 2992594 T10804 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 2992595 T10775 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2992599 T10806 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@37a682b2 name:ZooKeeperConnection Watcher:127.0.0.1:53131/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2992599 T10775 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2992602 T10775 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2992607 T10775 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 2992612 T10804 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 2992618 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2992622 T10804 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 2992622 T10804 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C5992 name=collection1 org.apache.solr.core.SolrCore@6c429838 url=http://127.0.0.1:53138/vagf/ur/collection1 node=127.0.0.1:53138_vagf%2Fur C5992_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:53138/vagf/ur, core=collection1, node_name=127.0.0.1:53138_vagf%2Fur}
   [junit4]   2> 2992622 T10804 C5992 P53138 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53138/vagf/ur/collection1/
   [junit4]   2> 2992622 T10804 C5992 P53138 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 2992622 T10804 C5992 P53138 oasc.SyncStrategy.syncToMe http://127.0.0.1:53138/vagf/ur/collection1/ has no replicas
   [junit4]   2> 2992622 T10804 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53138/vagf/ur/collection1/ shard1
   [junit4]   2> 2992624 T10804 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 2992626 T10798 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2992638 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2992640 T10806 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> 2992641 T10797 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> 2992653 T10798 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2992660 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2992791 T10806 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> 2992793 T10797 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> 2992830 T10804 oasc.ZkController.register We are http://127.0.0.1:53138/vagf/ur/collection1/ and leader is http://127.0.0.1:53138/vagf/ur/collection1/
   [junit4]   2> 2992831 T10804 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53138/vagf/ur
   [junit4]   2> 2992831 T10804 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 2992831 T10804 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 2992831 T10804 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2992834 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2992834 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2992834 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2992840 T10804 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2992843 T10798 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2992846 T10798 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:53138/vagf/ur",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53138_vagf%2Fur",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 2992854 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2992981 T10806 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> 2992985 T10797 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> 2994819 T10775 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 2994821 T10775 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 2994826 T10775 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53150
   [junit4]   2> 2994828 T10775 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 2994828 T10775 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2994828 T10775 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1394851789522
   [junit4]   2> 2994828 T10775 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1394851789522\'
   [junit4]   2> 2994862 T10775 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1394851789522\solr.xml
   [junit4]   2> 2994922 T10775 oasc.CoreContainer.<init> New CoreContainer 264811934
   [junit4]   2> 2994922 T10775 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1394851789522\]
   [junit4]   2> 2994925 T10775 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 2994926 T10775 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 2994926 T10775 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 2994926 T10775 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 2994926 T10775 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 2994926 T10775 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 2994926 T10775 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 2994926 T10775 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 2994926 T10775 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 2994935 T10775 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 2994935 T10775 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 2994935 T10775 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 2994935 T10775 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53131/solr
   [junit4]   2> 2994935 T10775 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2994937 T10775 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2994957 T10817 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@420ba02a name:ZooKeeperConnection Watcher:127.0.0.1:53131 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2994957 T10775 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2994963 T10777 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144c3a529c20005, 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:744)
   [junit4]   2> 
   [junit4]   2> 2994964 T10775 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2994970 T10819 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7e92613c name:ZooKeeperConnection Watcher:127.0.0.1:53131/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2994970 T10775 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2994988 T10775 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2996181 T10775 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53150_vagf%2Fur
   [junit4]   2> 2996188 T10775 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53150_vagf%2Fur
   [junit4]   2> 2996200 T10819 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 2996200 T10797 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 2996201 T10806 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 2996233 T10820 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 2996233 T10820 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2996238 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2996239 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2996240 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2996238 T10820 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 2996246 T10798 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2996248 T10798 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:53150/vagf/ur",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53150_vagf%2Fur",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 2996249 T10798 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 2996249 T10798 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 2996262 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2996266 T10819 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> 2996267 T10797 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> 2996268 T10806 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> 2997426 T10820 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 2997426 T10820 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1394851789522\collection1
   [junit4]   2> 2997426 T10820 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 2997429 T10820 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 2997429 T10820 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 2997431 T10820 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 2997432 T10820 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1394851789522\collection1\'
   [junit4]   2> 2997434 T10820 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1394851789522/collection1/lib/.svn/' to classloader
   [junit4]   2> 2997435 T10820 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1394851789522/collection1/lib/classes/' to classloader
   [junit4]   2> 2997436 T10820 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1394851789522/collection1/lib/README' to classloader
   [junit4]   2> 2997503 T10820 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 2997552 T10820 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 2997556 T10820 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 2997565 T10820 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 2998010 T10820 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2998014 T10820 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2998016 T10820 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2998022 T10820 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2998062 T10820 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 2998062 T10820 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1394851789522\collection1\, dataDir=.\org.apache.solr.cloud.ShardSplitTest-1394851785138/jetty1\
   [junit4]   2> 2998062 T10820 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2006650b
   [junit4]   2> 2998063 T10820 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1394851785138/jetty1\
   [junit4]   2> 2998063 T10820 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardSplitTest-1394851785138/jetty1\index/
   [junit4]   2> 2998063 T10820 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ShardSplitTest-1394851785138\jetty1\index' doesn't exist. Creating new index...
   [junit4]   2> 2998065 T10820 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1394851785138/jetty1\index
   [junit4]   2> 2998066 T10820 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=389407684, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 2998067 T10820 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@f5f0661 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7d8564a2),segFN=segments_1,generation=1}
   [junit4]   2> 2998067 T10820 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2998071 T10820 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 2998073 T10820 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 2998073 T10820 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 2998073 T10820 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2998073 T10820 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2998074 T10820 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 2998074 T10820 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2998074 T10820 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2998075 T10820 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 2998075 T10820 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 2998076 T10820 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 2998076 T10820 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 2998076 T10820 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 2998077 T10820 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 2998077 T10820 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 2998077 T10820 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 2998078 T10820 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 2998088 T10820 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2998096 T10820 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 2998096 T10820 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 2998097 T10820 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=18, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.18867959167681914]
   [junit4]   2> 2998098 T10820 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@f5f0661 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7d8564a2),segFN=segments_1,generation=1}
   [junit4]   2> 2998098 T10820 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2998099 T10820 oass.SolrIndexSearcher.<init> Opening Searcher@4d019851[collection1] main
   [junit4]   2> 2998099 T10820 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 2998103 T10820 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 2998103 T10820 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 2998105 T10820 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 2998105 T10820 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 2998105 T10820 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2998107 T10820 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 2998107 T10820 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2998107 T10820 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 2998107 T10820 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 2998112 T10821 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4d019851[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 2998114 T10820 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 2998117 T10775 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 2998117 T10775 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 2998117 T10824 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53150/vagf/ur collection:collection1 shard:shard2
   [junit4]   2> 2998119 T10824 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 2998139 T10824 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 2998143 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2998146 T10824 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 2998146 T10824 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C5993 name=collection1 org.apache.solr.core.SolrCore@51b2247b url=http://127.0.0.1:53150/vagf/ur/collection1 node=127.0.0.1:53150_vagf%2Fur C5993_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:53150/vagf/ur, core=collection1, node_name=127.0.0.1:53150_vagf%2Fur}
   [junit4]   2> 2998146 T10824 C5993 P53150 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53150/vagf/ur/collection1/
   [junit4]   2> 2998146 T10824 C5993 P53150 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 2998146 T10824 C5993 P53150 oasc.SyncStrategy.syncToMe http://127.0.0.1:53150/vagf/ur/collection1/ has no replicas
   [junit4]   2> 2998146 T10824 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53150/vagf/ur/collection1/ shard2
   [junit4]   2> 2998147 T10824 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 2998150 T10798 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2998161 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2998164 T10806 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> 2998164 T10797 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> 2998165 T10819 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> 2998177 T10798 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2998184 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2998310 T10819 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> 2998311 T10797 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> 2998311 T10806 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> 2998353 T10824 oasc.ZkController.register We are http://127.0.0.1:53150/vagf/ur/collection1/ and leader is http://127.0.0.1:53150/vagf/ur/collection1/
   [junit4]   2> 2998353 T10824 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53150/vagf/ur
   [junit4]   2> 2998353 T10824 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 2998353 T10824 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 2998353 T10824 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2998356 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2998356 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2998356 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2998358 T10824 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2998361 T10798 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2998362 T10798 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:53150/vagf/ur",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53150_vagf%2Fur",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 2998368 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2998496 T10797 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> 2998497 T10806 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> 2998497 T10819 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> 3000082 T10775 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 3000083 T10775 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 3000090 T10775 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53159
   [junit4]   2> 3000091 T10775 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 3000091 T10775 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 3000095 T10775 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1394851795030
   [junit4]   2> 3000095 T10775 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1394851795030\'
   [junit4]   2> 3000131 T10775 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1394851795030\solr.xml
   [junit4]   2> 3000192 T10775 oasc.CoreContainer.<init> New CoreContainer 669906447
   [junit4]   2> 3000192 T10775 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1394851795030\]
   [junit4]   2> 3000194 T10775 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 3000194 T10775 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 3000194 T10775 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 3000194 T10775 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 3000194 T10775 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 3000194 T10775 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 3000194 T10775 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 3000194 T10775 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 3000197 T10775 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 3000199 T10775 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 3000201 T10775 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 3000201 T10775 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 3000201 T10775 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53131/solr
   [junit4]   2> 3000201 T10775 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 3000205 T10775 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3000248 T10835 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@77b56743 name:ZooKeeperConnection Watcher:127.0.0.1:53131 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3000249 T10775 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3000252 T10777 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144c3a529c20007, 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:744)
   [junit4]   2> 
   [junit4]   2> 3000253 T10775 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3000264 T10837 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@58d0e4be name:ZooKeeperConnection Watcher:127.0.0.1:53131/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3000264 T10775 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3000279 T10775 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 3001484 T10775 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53159_vagf%2Fur
   [junit4]   2> 3001487 T10775 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53159_vagf%2Fur
   [junit4]   2> 3001493 T10837 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 3001493 T10806 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 3001493 T10797 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 3001494 T10819 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 3001511 T10838 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 3001511 T10838 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 3001513 T10838 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 3001513 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3001513 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3001513 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3001516 T10798 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3001518 T10798 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:53159/vagf/ur",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53159_vagf%2Fur",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 3001518 T10798 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 3001518 T10798 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 3001524 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3001526 T10819 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> 3001526 T10797 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> 3001527 T10806 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> 3001527 T10837 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> 3002817 T10838 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 3002817 T10838 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1394851795030\collection1
   [junit4]   2> 3002817 T10838 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 3002818 T10838 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 3002818 T10838 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 3002822 T10838 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 3002822 T10838 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1394851795030\collection1\'
   [junit4]   2> 3002824 T10838 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1394851795030/collection1/lib/.svn/' to classloader
   [junit4]   2> 3002827 T10838 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1394851795030/collection1/lib/classes/' to classloader
   [junit4]   2> 3002828 T10838 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1394851795030/collection1/lib/README' to classloader
   [junit4]   2> 3002904 T10838 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 3002963 T10838 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 3002965 T10838 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 3002976 T10838 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 3003471 T10838 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 3003473 T10838 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 3003476 T10838 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 3003502 T10838 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 3003555 T10838 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 3003556 T10838 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1394851795030\collection1\, dataDir=.\org.apache.solr.cloud.ShardSplitTest-1394851785138/jetty2\
   [junit4]   2> 3003556 T10838 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2006650b
   [junit4]   2> 3003557 T10838 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1394851785138/jetty2\
   [junit4]   2> 3003557 T10838 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardSplitTest-1394851785138/jetty2\index/
   [junit4]   2> 3003557 T10838 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ShardSplitTest-1394851785138\jetty2\index' doesn't exist. Creating new index...
   [junit4]   2> 3003558 T10838 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1394851785138/jetty2\index
   [junit4]   2> 3003558 T10838 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=389407684, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
   [junit4]   2> 3003560 T10838 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@3df5235 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7a585716),segFN=segments_1,generation=1}
   [junit4]   2> 3003560 T10838 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 3003565 T10838 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 3003565 T10838 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 3003566 T10838 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 3003566 T10838 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 3003566 T10838 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 3003566 T10838 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 3003567 T10838 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 3003567 T10838 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 3003567 T10838 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 3003569 T10838 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 3003569 T10838 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 3003570 T10838 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 3003570 T10838 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 3003570 T10838 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 3003571 T10838 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 3003571 T10838 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 3003572 T10838 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 3003584 T10838 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 3003590 T10838 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 3003590 T10838 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 3003592 T10838 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=18, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.18867959167681914]
   [junit4]   2> 3003592 T10838 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@3df5235 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7a585716),segFN=segments_1,generation=1}
   [junit4]   2> 3003593 T10838 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 3003593 T10838 oass.SolrIndexSearcher.<init> Opening Searcher@4a542c77[collection1] main
   [junit4]   2> 3003593 T10838 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 3003595 T10838 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 3003595 T10838 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 3003598 T10838 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 3003599 T10838 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 3003599 T10838 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3003600 T10838 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 3003600 T10838 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3003600 T10838 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 3003600 T10838 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 3003604 T10839 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4a542c77[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 3003608 T10838 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 3003609 T10775 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 3003611 T10842 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53159/vagf/ur collection:collection1 shard:shard1
   [junit4]   2> 3003611 T10775 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 3003613 T10842 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 3003627 T10842 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 3003635 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3003637 T10842 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 3003637 T10842 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C5994 name=collection1 org.apache.solr.core.SolrCore@281b0894 url=http://127.0.0.1:53159/vagf/ur/collection1 node=127.0.0.1:53159_vagf%2Fur C5994_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:53159/vagf/ur, core=collection1, node_name=127.0.0.1:53159_vagf%2Fur}
   [junit4]   2> 3003637 T10842 C5994 P53159 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53159/vagf/ur/collection1/
   [junit4]   2> 3003637 T10842 C5994 P53159 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 3003637 T10842 C5994 P53159 oasc.SyncStrategy.syncToMe http://127.0.0.1:53159/vagf/ur/collection1/ has no replicas
   [junit4]   2> 3003637 T10842 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53159/vagf/ur/collection1/ shard1
   [junit4]   2> 3003640 T10842 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3003642 T10798 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3003654 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3003658 T10797 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> 3003658 T10819 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> 3003658 T10837 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> 3003658 T10806 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> 3003668 T10798 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3003678 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3003823 T10806 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> 3003823 T10837 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> 3003824 T10797 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> 3003824 T10819 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> 3003864 T10842 oasc.ZkController.register We are http://127.0.0.1:53159/vagf/ur/collection1/ and leader is http://127.0.0.1:53159/vagf/ur/collection1/
   [junit4]   2> 3003865 T10842 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53159/vagf/ur
   [junit4]   2> 3003865 T10842 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 3003865 T10842 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 3003866 T10842 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 3003869 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3003870 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3003870 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3003873 T10842 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3003878 T10798 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3003879 T10798 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:53159/vagf/ur",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53159_vagf%2Fur",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 3003889 T10797 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3004034 T10819 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> 3004034 T10797 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> 3004036 T10806 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> 3004037 T10837 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> 3005810 T10775 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
   [junit4]   2> 3005810 T10775 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 3005817 T10775 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53168
   [junit4]   2> 3005822 T10775 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 3005822 T10775 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 3005822 T10775 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1394851800524
   [junit4]   2> 3005822 T10775 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1394851800524\'
   [junit4]   2> 3005862 T10775 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1394851800524\solr.xml
   [junit4]   2> 3005928 T10775 oasc.CoreContainer.<init> New CoreContainer 786061070
   [junit4]   2> 3005928 T10775 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1394851800524\]
   [junit4]   2> 3005931 T10775 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 3005931 T10775 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 3005931 T10775 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 3005931 T10775 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 3005931 T10775 oashc.HttpShardHandlerFactory.getParameter Setting corePo

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

[junit4]    > Throwable #1: java.lang.AssertionError: Wrong doc count on shard1_0 expected:<115> but was:<116>
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([21981B5EE79E5D7:83FF0FAD992685EB]:0)
   [junit4]    > 	at org.apache.solr.cloud.ShardSplitTest.checkDocCountsAndShardStates(ShardSplitTest.java:465)
   [junit4]    > 	at org.apache.solr.cloud.ShardSplitTest.splitByUniqueKeyTest(ShardSplitTest.java:237)
   [junit4]    > 	at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:101)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:870)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 3047182 T10775 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 58969 T10774 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
   [junit4]   2> NOTE: test params are: codec=Lucene41, sim=DefaultSimilarity, locale=en_MT, timezone=Pacific/Pohnpei
   [junit4]   2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.7.0_60-ea (64-bit)/cpus=2,threads=1,free=166886088,total=519438336
   [junit4]   2> NOTE: All tests run in this JVM: [TestSolrQueryParserDefaultOperatorResource, FunctionTest, DirectUpdateHandlerTest, PluginInfoTest, TestJmxIntegration, DeleteShardTest, DistributedQueryElevationComponentTest, TestLMDirichletSimilarityFactory, ZkSolrClientTest, UnloadDistributedZkTest, DebugComponentTest, TestUtils, TestSearcherReuse, TestDocumentBuilder, TestPseudoReturnFields, TestPhraseSuggestions, DirectSolrSpellCheckerTest, SignatureUpdateProcessorFactoryTest, DocValuesMultiTest, AbstractAnalyticsFacetTest, TimeZoneUtilsTest, TestOmitPositions, SynonymTokenizerTest, TestPerFieldSimilarity, TestStressVersions, TermVectorComponentTest, TestSurroundQueryParser, TestSolrDeletionPolicy1, AnalysisAfterCoreReloadTest, FileUtilsTest, TestExpandComponent, CoreAdminHandlerTest, LeaderElectionTest, TestSolrXmlPersistor, SliceStateTest, AsyncMigrateRouteKeyTest, TestManagedResourceStorage, TestIndexSearcher, CoreContainerCoreInitFailuresTest, SystemInfoHandlerTest, TestNonNRTOpen, SortByFunctionTest, DateFieldTest, JsonLoaderTest, TestAnalyzeInfixSuggestions, WordBreakSolrSpellCheckerTest, TestRandomDVFaceting, SimpleFacetsTest, TestDistributedMissingSort, StandardRequestHandlerTest, URLClassifyProcessorTest, TestSolr4Spatial, RecoveryZkTest, UpdateParamsTest, TestCloudManagedSchemaAddField, TestAtomicUpdateErrorCases, CollectionsAPIAsyncDistributedZkTest, ShowFileRequestHandlerTest, ZkCLITest, TestShardHandlerFactory, AssignTest, BinaryUpdateRequestHandlerTest, TestDynamicFieldCollectionResource, TestCopyFieldCollectionResource, TestZkChroot, OverseerRolesTest, TermsComponentTest, BadIndexSchemaTest, TermVectorComponentDistributedTest, DocumentBuilderTest, LoggingHandlerTest, IndexSchemaTest, StressHdfsTest, UniqFieldsUpdateProcessorFactoryTest, TestCharFilters, ChaosMonkeySafeLeaderTest, TestRequestStatusCollectionAPI, TestValueSourceCache, TestExtendedDismaxParser, ResourceLoaderTest, TestBlendedInfixSuggestions, TestAnalyzedSuggestions, SearchHandlerTest, FieldFacetExtrasTest, TestIndexingPerformance, BadCopyFieldTest, SuggesterWFSTTest, SampleTest, TestCustomSort, TestStressLucene, TestSolrIndexConfig, TestUniqueKeyFieldResource, SuggesterTest, TestSuggestSpellingConverter, SuggestComponentTest, SolrIndexSplitterTest, TestMaxScoreQueryParser, TestIBSimilarityFactory, TestDistributedSearch, TestManagedStopFilterFactory, DistanceFunctionTest, TestDocBasedVersionConstraints, TestDistributedGrouping, ShardRoutingCustomTest, SolrIndexConfigTest, TestCloudManagedSchema, TestDocSet, TestSolrCoreProperties, TestCollationFieldDocValues, XmlUpdateRequestHandlerTest, TestRangeQuery, FileBasedSpellCheckerTest, TestReplicationHandler, TestReversedWildcardFilterFactory, TestXIncludeConfig, TestFunctionQuery, CSVRequestHandlerTest, TestOverriddenPrefixQueryForCustomFieldType, XsltUpdateRequestHandlerTest, TestQuerySenderListener, TestSchemaVersionResource, IndexSchemaRuntimeFieldTest, SpellCheckCollatorTest, TestCollapseQParserPlugin, TestFiltering, ChangedSchemaMergeTest, TestFieldResource, TestCoreDiscovery, HighlighterTest, SOLR749Test, StatsComponentTest, SuggesterFSTTest, TestCSVResponseWriter, TestDFRSimilarityFactory, TestReloadAndDeleteDocs, UpdateRequestProcessorFactoryTest, TestAddFieldRealTimeGet, EchoParamsTest, EnumFieldTest, TestRandomFaceting, DistribCursorPagingTest, TestJmxMonitoredMap, QueryElevationComponentTest, TestArbitraryIndexDir, TestBadConfig, TestTrie, PathHierarchyTokenizerFactoryTest, TestRemoteStreaming, NumericFieldsTest, CoreMergeIndexesAdminHandlerTest, TestConfig, HdfsChaosMonkeySafeLeaderTest, RequiredFieldsTest, CoreAdminCreateDiscoverTest, AbstractAnalyticsStatsTest, ModifyConfFileTest, TestInfoStreamLogging, TestSolrDeletionPolicy2, TestExceedMaxTermLength, TestDynamicFieldResource, PrimitiveFieldTypeTest, TestCodecSupport, PrimUtilsTest, QueryEqualityTest, DistributedSuggestComponentTest, CursorMarkTest, TestMergePolicyConfig, TestFieldSortValues, DistributedTermsComponentTest, SolrCmdDistributorTest, TestFaceting, HdfsSyncSliceTest, HdfsLockFactoryTest, SchemaVersionSpecificBehaviorTest, BasicZkTest, DistributedDebugComponentTest, TestFastLRUCache, CoreAdminRequestStatusTest, TestRestManager, TestSystemIdResolver, PingRequestHandlerTest, ScriptEngineTest, TestUpdate, SolrXmlInZkTest, BasicDistributedZkTest, BasicDistributedZk2Test, CollectionsAPIDistributedZkTest, SyncSliceTest, OpenCloseCoreStressTest, OverseerTest, LeaderElectionIntegrationTest, ShardRoutingTest, FullSolrCloudDistribCmdsTest, ClusterStateUpdateTest, SliceStateUpdateTest, AutoCommitTest, TestRecovery, TestHashPartitioner, DistributedSpellCheckComponentTest, ZkControllerTest, TestRealTimeGet, TestStressReorder, TestJoin, TestMultiCoreConfBootstrap, TestReload, HardAutoCommitTest, TestCoreContainer, SolrCoreTest, SpellCheckComponentTest, TestGroupingSearch, PeerSyncTest, ConvertedLegacyTest, TestSort, BasicFunctionalityTest, TestLazyCores, OverseerCollectionProcessorTest, SoftAutoCommitTest, CurrencyFieldOpenExchangeTest, CurrencyFieldXmlFileTest, SimplePostToolTest, SolrRequestParserTest, TestFoldingMultitermQuery, DocValuesTest, SuggesterTSTTest, SpatialFilterTest, TestCSVLoader, PolyFieldTest, NoCacheHeaderTest, SolrCoreCheckLockOnStartupTest, FieldMutatingUpdateProcessorTest, TestWordDelimiterFilterFactory, DirectUpdateHandlerOptimizeTest, DefaultValueUpdateProcessorTest, StatelessScriptUpdateProcessorFactoryTest, SolrInfoMBeanTest, CacheHeaderTest, IndexBasedSpellCheckerTest, LukeRequestHandlerTest, DisMaxRequestHandlerTest, TestQueryUtils, TestWriterPerf, DocumentAnalysisRequestHandlerTest, TestQueryTypes, RequestHandlersTest, MoreLikeThisHandlerTest, FieldAnalysisRequestHandlerTest, TestSolrQueryParser, FastVectorHighlighterTest, RegexBoostProcessorTest, SolrPluginUtilsTest, TestCollationField, ReturnFieldsTest, JSONWriterTest, MBeansHandlerTest, QueryParsingTest, TestPartialUpdateDeduplication, TestPHPSerializedResponseWriter, TestComponentsName, TestBinaryResponseWriter, TestLFUCache, HighlighterConfigTest, AlternateDirectoryTest, TestQuerySenderNoQuery, CopyFieldTest, ResponseLogComponentTest, BadComponentTest, TestStressRecovery, MultiTermTest, TestBinaryField, TestSearchPerf, MinimalSchemaTest, TestElisionMultitermQuery, OutputWriterTest, TestFuzzyAnalyzedSuggestions, ExternalFileFieldSortTest, TestPostingsSolrHighlighter, DirectSolrConnectionTest, NotRequiredUniqueKeyTest, TestLuceneMatchVersion, SpellPossibilityIteratorTest, TestSweetSpotSimilarityFactory, TestNumberUtils, TestLMJelinekMercerSimilarityFactory, TestBM25SimilarityFactory, TestDefaultSimilarityFactory, TestFastWriter, LegacyHTMLStripCharFilterTest, TestFastOutputStream, OpenExchangeRatesOrgProviderTest, DateMathParserTest, ChaosMonkeyNothingIsSafeTest, TestSolrXMLSerializer, PreAnalyzedFieldTest, SpellingQueryConverterTest, DOMUtilTest, RAMDirectoryFactoryTest, ClusterStateTest, TestSolrJ, TestLRUCache, ZkNodePropsTest, UUIDFieldTest, CircularListTest, TestRTGBase, CursorPagingTest, SolrTestCaseJ4Test, TestCursorMarkWithoutUniqueKey, TestHighlightDedupGrouping, NoFacetTest, ExpressionTest, QueryFacetTest, RangeFacetTest, AliasIntegrationTest, ConnectionManagerTest, CustomCollectionTest, DeleteInactiveReplicaTest, DeleteReplicaTest, MigrateRouteKeyTest, RemoteQueryErrorTest, ShardSplitTest]
   [junit4] Completed in 59.68s, 1 test, 1 failure <<< FAILURES!

[...truncated 185 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:467: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:447: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:45: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\extra-targets.xml:37: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:189: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:490: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1275: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:907: There were test failures: 387 suites, 1633 tests, 1 failure, 54 ignored (33 assumptions)

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