lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-trunk-Windows (32bit/jdk1.7.0_67) - Build # 4399 - Still Failing!
Date Thu, 30 Oct 2014 12:50:43 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/4399/
Java: 32bit/jdk1.7.0_67 -server -XX:+UseConcMarkSweepGC

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

Error Message:
commitWithin did not work on node: http://127.0.0.1:54805/collection1 expected:<68> but was:<67>

Stack Trace:
java.lang.AssertionError: commitWithin did not work on node: http://127.0.0.1:54805/collection1 expected:<68> but was:<67>
	at __randomizedtesting.SeedInfo.seed([25C8DFA7ACA6E6F5:A42E51BFDBF986C9]: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.BasicDistributedZkTest.doTest(BasicDistributedZkTest.java:345)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:869)
	at sun.reflect.GeneratedMethodAccessor67.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:54)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at java.lang.Thread.run(Thread.java:745)




Build Log:
[...truncated 11058 lines...]
   [junit4] Suite: org.apache.solr.cloud.BasicDistributedZkTest
   [junit4]   2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\init-core-data-001
   [junit4]   2> 4208755 T9658 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 4208760 T9658 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> 4208762 T9658 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 4208764 T9659 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 4208860 T9658 oasc.ZkTestServer.run start zk server on port:54768
   [junit4]   2> 4208860 T9658 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 4208863 T9658 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4208867 T9665 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@160be17 name:ZooKeeperConnection Watcher:127.0.0.1:54768 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4208868 T9658 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4208868 T9658 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 4208868 T9658 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 4208874 T9658 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 4208876 T9658 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4208878 T9667 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f096a1 name:ZooKeeperConnection Watcher:127.0.0.1:54768/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4208879 T9658 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4208879 T9658 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 4208879 T9658 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 4208888 T9658 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 4208896 T9658 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 4208904 T9658 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 4208909 T9658 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> 4208910 T9658 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 4208917 T9658 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\core\src\test-files\solr\collection1\conf\schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 4208917 T9658 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 4208924 T9658 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> 4208924 T9658 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 4208931 T9658 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> 4208931 T9658 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 4208937 T9658 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> 4208937 T9658 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 4208942 T9658 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> 4208942 T9658 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 4208948 T9658 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> 4208948 T9658 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 4208954 T9658 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> 4208954 T9658 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 4208959 T9658 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> 4208960 T9658 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 4208965 T9658 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> 4208965 T9658 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 4208970 T9658 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> 4208972 T9658 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 4210939 T9658 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 4210950 T9658 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54775
   [junit4]   2> 4210950 T9658 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 4210950 T9658 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 4210950 T9658 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-002
   [junit4]   2> 4210950 T9658 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-002\'
   [junit4]   2> 4210993 T9658 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-002\solr.xml
   [junit4]   2> 4211106 T9658 oasc.CoreContainer.<init> New CoreContainer 1222590
   [junit4]   2> 4211106 T9658 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-002\]
   [junit4]   2> 4211110 T9658 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 4211110 T9658 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 4211110 T9658 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 4211110 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 4211110 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
   [junit4]   2> 4211110 T9658 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 4211110 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 4211110 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 4211111 T9658 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 4211111 T9658 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 4211111 T9658 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
   [junit4]   2> 4211114 T9658 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 4211114 T9658 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 4211114 T9658 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 4211114 T9658 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:54768/solr
   [junit4]   2> 4211114 T9658 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 4211114 T9658 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 4211118 T9658 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4211121 T9678 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c2c293 name:ZooKeeperConnection Watcher:127.0.0.1:54768 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4211122 T9658 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4211122 T9658 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 4211127 T9658 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4211147 T9680 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@103cd8c name:ZooKeeperConnection Watcher:127.0.0.1:54768/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4211148 T9658 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4211150 T9658 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 4211156 T9658 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 4211162 T9658 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 4211168 T9658 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 4211174 T9658 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 4211180 T9658 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 4211184 T9658 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54775_
   [junit4]   2> 4211185 T9658 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54775_
   [junit4]   2> 4211191 T9658 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 4211195 T9658 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 4211200 T9658 oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 4211204 T9658 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:54775_
   [junit4]   2> 4211204 T9658 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 4211208 T9658 oasc.Overseer.start Overseer (id=92711792594124803-127.0.0.1:54775_-n_0000000000) starting
   [junit4]   2> 4211213 T9658 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 4211233 T9658 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
   [junit4]   2> 4211235 T9682 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 4211237 T9658 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 4211243 T9658 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 4211247 T9658 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 4211255 T9681 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 4211261 T9684 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 4211262 T9684 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 4211262 T9684 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 4211263 T9685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 4211269 T9681 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:54775",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "node_name":"127.0.0.1:54775_",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core":"collection1"}
   [junit4]   2> 4211269 T9681 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 4211269 T9681 oasc.Overseer$ClusterStateUpdater.createCollection state version control_collection 1
   [junit4]   2> 4211269 T9681 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 4211275 T9685 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> 4212301 T9684 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 4212301 T9684 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 4212302 T9684 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 4212302 T9684 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 4212305 T9684 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 4212305 T9684 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-002\collection1\'
   [junit4]   2> 4212308 T9684 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001/tempDir-002/collection1/lib/.svn/' to classloader
   [junit4]   2> 4212311 T9684 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001/tempDir-002/collection1/lib/classes/' to classloader
   [junit4]   2> 4212313 T9684 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001/tempDir-002/collection1/lib/README' to classloader
   [junit4]   2> 4212386 T9684 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 4212453 T9684 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 4212456 T9684 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 4212465 T9684 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 4212903 T9684 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 4212912 T9684 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 4212915 T9684 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 4212949 T9684 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 4212954 T9684 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 4212959 T9684 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 4212961 T9684 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 4212962 T9684 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 4212962 T9684 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 4212964 T9684 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 4212964 T9684 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 4212964 T9684 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 4212964 T9684 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 4212966 T9684 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-002\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-001/control/data\
   [junit4]   2> 4212966 T9684 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@17f8627
   [junit4]   2> 4212967 T9684 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-001/control/data\
   [junit4]   2> 4212967 T9684 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-001/control/data\index/
   [junit4]   2> 4212967 T9684 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-001\control\data\index' doesn't exist. Creating new index...
   [junit4]   2> 4212968 T9684 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-001/control/data\index
   [junit4]   2> 4212968 T9684 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=22, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 4212969 T9684 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-1f322b5)),segFN=segments_1,generation=1}
   [junit4]   2> 4212969 T9684 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 4212973 T9684 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 4212973 T9684 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 4212973 T9684 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 4212974 T9684 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 4212974 T9684 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 4212974 T9684 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 4212975 T9684 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 4212975 T9684 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 4212975 T9684 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 4212976 T9684 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4212976 T9684 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4212977 T9684 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4212977 T9684 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 4212977 T9684 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 4212978 T9684 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 4212978 T9684 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 4212978 T9684 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 4212979 T9684 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 4212979 T9684 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 4212979 T9684 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 4212993 T9684 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4212995 T9684 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4212999 T9684 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4213001 T9684 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4213010 T9684 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 4213010 T9684 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 4213012 T9684 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=44, maxMergeAtOnceExplicit=15, maxMergedSegmentMB=64.41015625, floorSegmentMB=0.203125, forceMergeDeletesPctAllowed=16.00541628600708, segmentsPerTier=44.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8234737136161981
   [junit4]   2> 4213013 T9684 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-1f322b5)),segFN=segments_1,generation=1}
   [junit4]   2> 4213013 T9684 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 4213014 T9684 oass.SolrIndexSearcher.<init> Opening Searcher@e3f2d1[collection1] main
   [junit4]   2> 4213014 T9684 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 4213016 T9684 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 4213016 T9684 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 4213018 T9684 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 4213018 T9684 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 4213018 T9684 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 4213019 T9684 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 4213019 T9684 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 4213021 T9684 oascc.SolrZkClient.makePath makePath: /configs/conf1/_rest_managed.json
   [junit4]   2> 4213025 T9684 oasr.ManagedResourceStorage$ZooKeeperStorageIO$1.close Wrote 38 bytes to new znode /configs/conf1/_rest_managed.json
   [junit4]   2> 4213025 T9684 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 4213025 T9684 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 4213028 T9686 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@e3f2d1[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 4213030 T9684 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 4213032 T9689 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54775 collection:control_collection shard:shard1
   [junit4]   2> 4213032 T9658 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 4213033 T9658 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 4213034 T9658 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 4213035 T9689 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 4213036 T9658 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4213038 T9691 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d62f0a name:ZooKeeperConnection Watcher:127.0.0.1:54768/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4213039 T9658 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4213039 T9658 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 4213041 T9658 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 4213049 T9689 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 4213051 T9658 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 4213054 T9685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 4213057 T9689 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 4213057 T9689 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C4634 name=collection1 org.apache.solr.core.SolrCore@10af15b url=http://127.0.0.1:54775/collection1 node=127.0.0.1:54775_ C4634_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:54775, node_name=127.0.0.1:54775_, core=collection1}
   [junit4]   2> 4213057 T9689 C4634 P54775 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54775/collection1/
   [junit4]   2> 4213057 T9689 C4634 P54775 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 4213057 T9689 C4634 P54775 oasc.SyncStrategy.syncToMe http://127.0.0.1:54775/collection1/ has no replicas
   [junit4]   2> 4213058 T9689 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54775/collection1/ shard1
   [junit4]   2> 4213059 T9689 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 4213082 T9685 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> 4213087 T9692 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> 4213118 T9685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 4213120 T9685 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> 4213121 T9692 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> 4213138 T9689 oasc.ZkController.register We are http://127.0.0.1:54775/collection1/ and leader is http://127.0.0.1:54775/collection1/
   [junit4]   2> 4213138 T9689 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54775
   [junit4]   2> 4213138 T9689 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 4213138 T9689 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 4213138 T9689 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 4213141 T9685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 4213159 T9681 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:54775",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "node_name":"127.0.0.1:54775_",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "core":"collection1"}
   [junit4]   2> 4213282 T9685 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> 4213282 T9692 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> 4214723 T9658 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 4214724 T9658 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 4214729 T9658 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54787
   [junit4]   2> 4214730 T9658 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 4214730 T9658 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 4214730 T9658 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-003
   [junit4]   2> 4214731 T9658 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-003\'
   [junit4]   2> 4214764 T9658 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-003\solr.xml
   [junit4]   2> 4214828 T9658 oasc.CoreContainer.<init> New CoreContainer 2565472
   [junit4]   2> 4214828 T9658 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-003\]
   [junit4]   2> 4214830 T9658 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 4214831 T9658 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 4214831 T9658 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 4214831 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 4214831 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
   [junit4]   2> 4214831 T9658 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 4214831 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 4214831 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 4214833 T9658 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 4214833 T9658 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 4214833 T9658 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
   [junit4]   2> 4214833 T9658 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 4214833 T9658 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 4214836 T9658 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 4214836 T9658 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:54768/solr
   [junit4]   2> 4214836 T9658 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 4214836 T9658 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 4214840 T9658 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4214841 T9703 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6c2ba name:ZooKeeperConnection Watcher:127.0.0.1:54768 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4214842 T9658 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4214842 T9658 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 4214845 T9660 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x14960e258100005, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 
   [junit4]   2> 4214848 T9658 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4214849 T9705 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1dee4d9 name:ZooKeeperConnection Watcher:127.0.0.1:54768/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4214849 T9658 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4214862 T9658 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 4215921 T9658 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54787_
   [junit4]   2> 4215921 T9658 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54787_
   [junit4]   2> 4215929 T9658 oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 4215949 T9707 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 4215949 T9707 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 4215951 T9685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 4215951 T9707 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 4215957 T9681 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:54787",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "node_name":"127.0.0.1:54787_",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core":"collection1"}
   [junit4]   2> 4215957 T9681 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 4215959 T9681 oasc.Overseer$ClusterStateUpdater.createCollection state version collection1 1
   [junit4]   2> 4215959 T9681 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 4215965 T9706 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> 4215965 T9685 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> 4215965 T9692 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> 4217001 T9707 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 4217001 T9707 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 4217002 T9707 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 4217003 T9707 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 4217005 T9707 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 4217005 T9707 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-003\collection1\'
   [junit4]   2> 4217007 T9707 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001/tempDir-003/collection1/lib/.svn/' to classloader
   [junit4]   2> 4217007 T9707 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001/tempDir-003/collection1/lib/classes/' to classloader
   [junit4]   2> 4217007 T9707 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001/tempDir-003/collection1/lib/README' to classloader
   [junit4]   2> 4217068 T9707 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 4217116 T9707 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 4217118 T9707 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 4217127 T9707 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 4217625 T9707 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 4217637 T9707 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 4217640 T9707 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 4217662 T9707 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 4217668 T9707 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 4217674 T9707 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 4217677 T9707 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 4217678 T9707 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 4217678 T9707 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 4217680 T9707 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 4217680 T9707 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 4217681 T9707 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 4217681 T9707 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 4217681 T9707 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-003\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-001/jetty1\
   [junit4]   2> 4217682 T9707 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@17f8627
   [junit4]   2> 4217682 T9707 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-001/jetty1\
   [junit4]   2> 4217683 T9707 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-001/jetty1\index/
   [junit4]   2> 4217683 T9707 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-001\jetty1\index' doesn't exist. Creating new index...
   [junit4]   2> 4217683 T9707 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-001/jetty1\index
   [junit4]   2> 4217684 T9707 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=22, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 4217684 T9707 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-b77287)),segFN=segments_1,generation=1}
   [junit4]   2> 4217685 T9707 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 4217689 T9707 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 4217690 T9707 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 4217690 T9707 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 4217691 T9707 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 4217691 T9707 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 4217691 T9707 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 4217692 T9707 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 4217692 T9707 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 4217692 T9707 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 4217693 T9707 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4217693 T9707 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4217694 T9707 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4217694 T9707 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 4217696 T9707 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 4217696 T9707 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 4217696 T9707 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 4217698 T9707 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 4217698 T9707 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 4217699 T9707 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 4217699 T9707 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 4217712 T9707 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4217714 T9707 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4217717 T9707 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4217719 T9707 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4217724 T9707 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 4217724 T9707 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 4217725 T9707 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=44, maxMergeAtOnceExplicit=15, maxMergedSegmentMB=64.41015625, floorSegmentMB=0.203125, forceMergeDeletesPctAllowed=16.00541628600708, segmentsPerTier=44.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8234737136161981
   [junit4]   2> 4217726 T9707 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-b77287)),segFN=segments_1,generation=1}
   [junit4]   2> 4217726 T9707 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 4217726 T9707 oass.SolrIndexSearcher.<init> Opening Searcher@15fd274[collection1] main
   [junit4]   2> 4217726 T9707 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 4217729 T9707 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 4217729 T9707 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 4217731 T9707 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 4217731 T9707 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 4217731 T9707 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 4217733 T9707 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json
   [junit4]   2> 4217733 T9707 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 4217733 T9707 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed
   [junit4]   2> 4217733 T9707 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 4217742 T9708 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@15fd274[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 4217746 T9707 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 4217748 T9711 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54787 collection:collection1 shard:shard2
   [junit4]   2> 4217749 T9658 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 4217749 T9658 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 4217751 T9711 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 4217766 T9711 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 4217769 T9685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 4217770 T9711 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 4217770 T9711 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C4635 name=collection1 org.apache.solr.core.SolrCore@712d79 url=http://127.0.0.1:54787/collection1 node=127.0.0.1:54787_ C4635_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:54787, node_name=127.0.0.1:54787_, core=collection1}
   [junit4]   2> 4217770 T9711 C4635 P54787 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54787/collection1/
   [junit4]   2> 4217770 T9711 C4635 P54787 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 4217770 T9711 C4635 P54787 oasc.SyncStrategy.syncToMe http://127.0.0.1:54787/collection1/ has no replicas
   [junit4]   2> 4217772 T9711 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54787/collection1/ shard2
   [junit4]   2> 4217772 T9711 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 4217799 T9685 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> 4217799 T9692 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> 4217800 T9706 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> 4217828 T9685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 4217831 T9685 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> 4217831 T9706 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> 4217833 T9692 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> 4217852 T9711 oasc.ZkController.register We are http://127.0.0.1:54787/collection1/ and leader is http://127.0.0.1:54787/collection1/
   [junit4]   2> 4217852 T9711 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54787
   [junit4]   2> 4217852 T9711 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 4217852 T9711 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 4217852 T9711 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 4217855 T9685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 4217867 T9681 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:54787",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "node_name":"127.0.0.1:54787_",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "core":"collection1"}
   [junit4]   2> 4217980 T9685 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> 4217981 T9692 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> 4217982 T9706 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> 4219630 T9658 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 4219631 T9658 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 4219635 T9658 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54796
   [junit4]   2> 4219637 T9658 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 4219638 T9658 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 4219638 T9658 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-004
   [junit4]   2> 4219639 T9658 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-004\'
   [junit4]   2> 4219684 T9658 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-004\solr.xml
   [junit4]   2> 4219769 T9658 oasc.CoreContainer.<init> New CoreContainer 7308798
   [junit4]   2> 4219769 T9658 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-004\]
   [junit4]   2> 4219772 T9658 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 4219772 T9658 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 4219772 T9658 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 4219772 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 4219772 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
   [junit4]   2> 4219772 T9658 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 4219772 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 4219772 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 4219772 T9658 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 4219772 T9658 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 4219775 T9658 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
   [junit4]   2> 4219775 T9658 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 4219775 T9658 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 4219775 T9658 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 4219775 T9658 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:54768/solr
   [junit4]   2> 4219778 T9658 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 4219778 T9658 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 4219780 T9658 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4219783 T9722 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c5eb05 name:ZooKeeperConnection Watcher:127.0.0.1:54768 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4219784 T9658 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4219784 T9658 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 4219789 T9658 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4219791 T9724 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3dc324 name:ZooKeeperConnection Watcher:127.0.0.1:54768/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4219791 T9658 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4219803 T9658 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 4220862 T9658 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54796_
   [junit4]   2> 4220863 T9658 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54796_
   [junit4]   2> 4220871 T9658 oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 4220881 T9726 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 4220881 T9726 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 4220882 T9685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 4220884 T9726 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 4220888 T9681 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:54796",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "node_name":"127.0.0.1:54796_",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core":"collection1"}
   [junit4]   2> 4220889 T9681 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 4220889 T9681 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 4220893 T9685 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> 4220893 T9706 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> 4220893 T9725 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> 4220893 T9692 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> 4221938 T9726 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 4221938 T9726 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 4221941 T9726 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 4221941 T9726 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 4221943 T9726 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 4221943 T9726 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-004\collection1\'
   [junit4]   2> 4221946 T9726 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001/tempDir-004/collection1/lib/.svn/' to classloader
   [junit4]   2> 4221948 T9726 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001/tempDir-004/collection1/lib/classes/' to classloader
   [junit4]   2> 4221949 T9726 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/temp/solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001/tempDir-004/collection1/lib/README' to classloader
   [junit4]   2> 4222036 T9726 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 4222109 T9726 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 4222111 T9726 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 4222124 T9726 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 4222577 T9726 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 4222594 T9726 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 4222600 T9726 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 4222626 T9726 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 4222633 T9726 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 4222640 T9726 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 4222642 T9726 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 4222642 T9726 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 4222642 T9726 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 4222645 T9726 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 4222645 T9726 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 4222645 T9726 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 4222645 T9726 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 4222646 T9726 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-004\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-001/jetty2\
   [junit4]   2> 4222646 T9726 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@17f8627
   [junit4]   2> 4222647 T9726 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-001/jetty2\
   [junit4]   2> 4222647 T9726 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-001/jetty2\index/
   [junit4]   2> 4222647 T9726 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-001\jetty2\index' doesn't exist. Creating new index...
   [junit4]   2> 4222647 T9726 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-001/jetty2\index
   [junit4]   2> 4222649 T9726 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=22, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 4222649 T9726 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-16dbcc2)),segFN=segments_1,generation=1}
   [junit4]   2> 4222649 T9726 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 4222655 T9726 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 4222656 T9726 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 4222656 T9726 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 4222656 T9726 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 4222656 T9726 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 4222656 T9726 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 4222658 T9726 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 4222658 T9726 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 4222658 T9726 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 4222659 T9726 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4222659 T9726 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4222660 T9726 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4222660 T9726 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 4222661 T9726 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 4222661 T9726 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 4222661 T9726 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 4222662 T9726 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 4222662 T9726 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 4222663 T9726 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 4222663 T9726 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 4222675 T9726 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4222675 T9726 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4222678 T9726 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4222681 T9726 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4222687 T9726 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 4222688 T9726 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 4222689 T9726 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=44, maxMergeAtOnceExplicit=15, maxMergedSegmentMB=64.41015625, floorSegmentMB=0.203125, forceMergeDeletesPctAllowed=16.00541628600708, segmentsPerTier=44.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8234737136161981
   [junit4]   2> 4222689 T9726 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory(id=lucene-16dbcc2)),segFN=segments_1,generation=1}
   [junit4]   2> 4222689 T9726 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 4222690 T9726 oass.SolrIndexSearcher.<init> Opening Searcher@620c67[collection1] main
   [junit4]   2> 4222690 T9726 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 4222693 T9726 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 4222693 T9726 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 4222694 T9726 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 4222694 T9726 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 4222694 T9726 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 4222697 T9726 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json
   [junit4]   2> 4222697 T9726 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 4222697 T9726 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed
   [junit4]   2> 4222697 T9726 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 4222702 T9727 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@620c67[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 4222704 T9726 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 4222706 T9730 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54796 collection:collection1 shard:shard1
   [junit4]   2> 4222707 T9658 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 4222709 T9658 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 4222711 T9730 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 4222735 T9730 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 4222740 T9685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 4222743 T9730 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 4222743 T9730 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C4636 name=collection1 org.apache.solr.core.SolrCore@8f4a84 url=http://127.0.0.1:54796/collection1 node=127.0.0.1:54796_ C4636_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:54796, node_name=127.0.0.1:54796_, core=collection1}
   [junit4]   2> 4222743 T9730 C4636 P54796 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54796/collection1/
   [junit4]   2> 4222743 T9730 C4636 P54796 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 4222743 T9730 C4636 P54796 oasc.SyncStrategy.syncToMe http://127.0.0.1:54796/collection1/ has no replicas
   [junit4]   2> 4222744 T9730 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54796/collection1/ shard1
   [junit4]   2> 4222746 T9730 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 4222792 T9725 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> 4222794 T9685 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> 4222794 T9706 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> 4222795 T9692 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> 4222834 T9685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 4222837 T9685 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> 4222838 T9706 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> 4222838 T9692 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> 4222839 T9725 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> 4222852 T9730 oasc.ZkController.register We are http://127.0.0.1:54796/collection1/ and leader is http://127.0.0.1:54796/collection1/
   [junit4]   2> 4222852 T9730 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54796
   [junit4]   2> 4222852 T9730 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 4222852 T9730 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 4222852 T9730 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 4222862 T9731 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 4222867 T9681 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:54796",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "node_name":"127.0.0.1:54796_",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "core":"collection1"}
   [junit4]   2> 4222989 T9731 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> 4222990 T9725 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> 4222990 T9706 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> 4222992 T9692 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> 4224789 T9658 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
   [junit4]   2> 4224790 T9658 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 4224797 T9658 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54805
   [junit4]   2> 4224799 T9658 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 4224799 T9658 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 4224799 T9658 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-005
   [junit4]   2> 4224799 T9658 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-005\'
   [junit4]   2> 4224849 T9658 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\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-005\solr.xml
   [junit4]   2> 4224971 T9658 oasc.CoreContainer.<init> New CoreContainer 29881098
   [junit4]   2> 4224972 T9658 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001\tempDir-005\]
   [junit4]   2> 4224974 T9658 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 4224975 T9658 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 4224975 T9658 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 4224975 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 4224976 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
   [junit4]   2> 4224976 T9658 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 4224978 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 4224978 T9658 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 4224979 T9658 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1


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

mmon.cloud.SolrZkClient$3.process(SolrZkClient.java:263)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> 
   [junit4]   2> 4281129 T9800 oaz.ClientCnxn$EventThread.processEvent ERROR Error while calling watcher  java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.FutureTask@1ff16d7 rejected from java.util.concurrent.ThreadPoolExecutor@1be86a0[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 16]
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor$AbortPolicy.rejectedExecution(ThreadPoolExecutor.java:2048)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor.reject(ThreadPoolExecutor.java:821)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1372)
   [junit4]   2> 	at java.util.concurrent.AbstractExecutorService.submit(AbstractExecutorService.java:110)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$3.process(SolrZkClient.java:263)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
   [junit4]   2> 
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=BasicDistributedZkTest -Dtests.method=testDistribSearch -Dtests.seed=25C8DFA7ACA6E6F5 -Dtests.slow=true -Dtests.locale=es_EC -Dtests.timezone=Indian/Maldives -Dtests.asserts=true -Dtests.file.encoding=UTF-8
   [junit4] FAILURE 72.4s | BasicDistributedZkTest.testDistribSearch <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: commitWithin did not work on node: http://127.0.0.1:54805/collection1 expected:<68> but was:<67>
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([25C8DFA7ACA6E6F5:A42E51BFDBF986C9]:0)
   [junit4]    > 	at org.apache.solr.cloud.BasicDistributedZkTest.doTest(BasicDistributedZkTest.java:345)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:869)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 4281140 T9658 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.BasicDistributedZkTest-25C8DFA7ACA6E6F5-001
   [junit4]   2> 72391 T9657 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene50): {id=PostingsFormat(name=Direct), foo_b=PostingsFormat(name=LuceneVarGapFixedInterval), _version_=BlockTreeOrds(blocksize=128), foo_f=PostingsFormat(name=LuceneVarGapFixedInterval), foo_i=BlockTreeOrds(blocksize=128), other_tl1=BlockTreeOrds(blocksize=128), SubjectTerms_mfacet=BlockTreeOrds(blocksize=128), n_tl1=BlockTreeOrds(blocksize=128), n_d1=PostingsFormat(name=LuceneVarGapDocFreqInterval), timestamp=PostingsFormat(name=LuceneVarGapDocFreqInterval), n_dt1=BlockTreeOrds(blocksize=128), foo_d=PostingsFormat(name=Direct), n_tdt1=BlockTreeOrds(blocksize=128), n_f1=BlockTreeOrds(blocksize=128), intDefault=BlockTreeOrds(blocksize=128), a_i1=PostingsFormat(name=LuceneVarGapDocFreqInterval), rnd_b=PostingsFormat(name=Direct), n_tf1=PostingsFormat(name=LuceneVarGapDocFreqInterval), n_l1=PostingsFormat(name=LuceneVarGapDocFreqInterval), multiDefault=PostingsFormat(name=LuceneVarGapDocFreqInterval), a_t=PostingsFormat(name=LuceneVarGapDocFreqInterval), text=PostingsFormat(name=LuceneVarGapFixedInterval), n_ti1=PostingsFormat(name=Direct), n_td1=BlockTreeOrds(blocksize=128), oddField_s=PostingsFormat(name=Direct), range_facet_l=PostingsFormat(name=LuceneVarGapDocFreqInterval)}, docValues:{timestamp=DocValuesFormat(name=SimpleText)}, sim=DefaultSimilarity, locale=es_EC, timezone=Indian/Maldives
   [junit4]   2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.7.0_67 (32-bit)/cpus=2,threads=1,free=222459448,total=523501568
   [junit4]   2> NOTE: All tests run in this JVM: [DirectUpdateHandlerOptimizeTest, TestInitParams, AnalysisAfterCoreReloadTest, TestBulkSchemaAPI, TestCollationFieldDocValues, NumericFieldsTest, TestManagedSchemaFieldResource, ShardRoutingTest, BadCopyFieldTest, StatelessScriptUpdateProcessorFactoryTest, CSVRequestHandlerTest, OverseerRolesTest, BlockDirectoryTest, UUIDFieldTest, TestPerFieldSimilarity, TestCopyFieldCollectionResource, TestTrie, TestFieldTypeCollectionResource, DisMaxRequestHandlerTest, EnumFieldTest, PreAnalyzedUpdateProcessorTest, TestRangeQuery, ExitableDirectoryReaderTest, TestSchemaResource, DistributedDebugComponentTest, DateMathParserTest, TestCoreDiscovery, TestXIncludeConfig, RecoveryZkTest, UnloadDistributedZkTest, TestShortCircuitedRequests, ShowFileRequestHandlerTest, StandardRequestHandlerTest, TestCollapseQParserPlugin, TestRandomMergePolicy, SortByFunctionTest, PeerSyncTest, TestInitQParser, ConvertedLegacyTest, TestComplexPhraseQParserPlugin, TestSimpleQParserPlugin, DistributedSpellCheckComponentTest, LeaderElectionTest, DistributedFacetPivotSmallTest, TestCloudManagedSchemaConcurrent, UpdateParamsTest, UniqFieldsUpdateProcessorFactoryTest, PreAnalyzedFieldTest, TestFunctionQuery, TestSurroundQueryParser, DistributedQueryComponentOptimizationTest, SolrCmdDistributorTest, UUIDUpdateProcessorFallbackTest, TestReplicaProperties, TestIndexSearcher, TestIntervalFaceting, TestReplicationHandler, CoreAdminRequestStatusTest, SolrIndexConfigTest, FullSolrCloudDistribCmdsTest, MultiTermTest, InfoHandlerTest, TestCoreContainer, EchoParamsTest, TestExceedMaxTermLength, TestManagedResource, JsonLoaderTest, TestRecoveryHdfs, TestDistributedSearch, ShardSplitTest, ClusterStateUpdateTest, CursorMarkTest, TestManagedResourceStorage, HdfsUnloadDistributedZkTest, TestSolrCoreProperties, TestQuerySenderNoQuery, HdfsDirectoryTest, TestAddFieldRealTimeGet, DocValuesTest, TestElisionMultitermQuery, TestSolrIndexConfig, RequiredFieldsTest, TestExtendedDismaxParser, TestSolrDeletionPolicy1, TestExpandComponent, BasicDistributedZk2Test, LeaderInitiatedRecoveryOnCommitTest, TestManagedSynonymFilterFactory, TestBinaryResponseWriter, CoreAdminCreateDiscoverTest, SharedFSAutoReplicaFailoverTest, HdfsChaosMonkeySafeLeaderTest, AddBlockUpdateTest, TestRTGBase, TestSolr4Spatial, TestConfig, SolrCoreTest, DistributedFacetPivotLongTailTest, IndexSchemaRuntimeFieldTest, MigrateRouteKeyTest, TestSchemaNameResource, TestShardHandlerFactory, RankQueryTest, ZkControllerTest, TestArbitraryIndexDir, SolrInfoMBeanTest, OutputWriterTest, TestGroupingSearch, TestMultiCoreConfBootstrap, SSLMigrationTest, TestSchemaManager, TestSearcherReuse, XmlUpdateRequestHandlerTest, FileBasedSpellCheckerTest, HttpPartitionTest, RollingRestartTest, PingRequestHandlerTest, DistribCursorPagingTest, DistributedQueryElevationComponentTest, TestNonDefinedSimilarityFactory, SimpleFacetsTest, SolrCoreCheckLockOnStartupTest, BasicFunctionalityTest, TestManagedSchemaFieldTypeResource, DeleteReplicaTest, DistributedExpandComponentTest, CollectionsAPIAsyncDistributedZkTest, TestRawResponseWriter, SOLR749Test, SpellCheckCollatorTest, TestWriterPerf, DocExpirationUpdateProcessorFactoryTest, DistribDocExpirationUpdateProcessorTest, TestSolr4Spatial2, VMParamsZkACLAndCredentialsProvidersTest, AssignTest, AsyncMigrateRouteKeyTest, PolyFieldTest, TestDefaultSimilarityFactory, OutOfBoxZkACLAndCredentialsProvidersTest, TestUniqueKeyFieldResource, TestSchemaVersionResource, DateFieldTest, ShardRoutingCustomTest, SampleTest, TestPostingsSolrHighlighter, HdfsWriteToMultipleCollectionsTest, TestFaceting, ZkNodePropsTest, DocumentAnalysisRequestHandlerTest, OverriddenZkACLAndCredentialsProvidersTest, TestStressReorder, TestBM25SimilarityFactory, TestDocumentBuilder, TestDistributedGrouping, TestSweetSpotSimilarityFactory, XsltUpdateRequestHandlerTest, TestDynamicFieldCollectionResource, RemoteQueryErrorTest, TestJmxMonitoredMap, ClusterStateTest, TestLMDirichletSimilarityFactory, TestDFRSimilarityFactory, TestConfigSets, TestLazyCores, PrimitiveFieldTypeTest, DocumentBuilderTest, TestPivotHelperCode, TestSolrQueryParserResource, SimpleMLTQParserTest, HighlighterTest, TestReload, SimplePostToolTest, AnalyticsQueryTest, TestDocSet, DateRangeFieldTest, BasicDistributedZkTest]
   [junit4] Completed in 72.72s, 1 test, 1 failure <<< FAILURES!

[...truncated 814 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:525: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:473: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:61: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\extra-targets.xml:39: 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:496: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1358: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:965: There were test failures: 440 suites, 1800 tests, 1 failure, 53 ignored (30 assumptions)

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



Mime
View raw message