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

[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.8.0) - Build # 1803 - Failure!

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

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

Error Message:
reloadcollection the collection time out:180s

Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: reloadcollection the collection time out:180s
	at __randomizedtesting.SeedInfo.seed([5A92393B9AB95AF1:DB74B723EDE63ACD]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:550)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:210)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:206)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.invokeCollectionApi(AbstractFullDistribZkTestBase.java:1744)
	at org.apache.solr.cloud.OverseerStatusTest.doTest(OverseerStatusTest.java:103)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:869)
	at sun.reflect.GeneratedMethodAccessor36.invoke(Unknown Source)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:483)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java: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:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at java.lang.Thread.run(Thread.java:745)




Build Log:
[...truncated 11983 lines...]
   [junit4] Suite: org.apache.solr.cloud.OverseerStatusTest
   [junit4]   2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/init-core-data-001
   [junit4]   2> 4546194 T12012 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /_n/df
   [junit4]   2> 4546198 T12012 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> 4546199 T12012 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 4546200 T12013 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 4546301 T12012 oasc.ZkTestServer.run start zk server on port:52300
   [junit4]   2> 4546301 T12012 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 4546306 T12012 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4546316 T12019 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@449af40b name:ZooKeeperConnection Watcher:127.0.0.1:52300 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4546317 T12012 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4546318 T12012 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 4546318 T12012 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 4546325 T12012 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 4546328 T12012 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4546329 T12021 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@27763864 name:ZooKeeperConnection Watcher:127.0.0.1:52300/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4546329 T12012 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4546330 T12012 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 4546330 T12012 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 4546336 T12012 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 4546341 T12012 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 4546345 T12012 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 4546350 T12012 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 4546351 T12012 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 4546358 T12012 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
   [junit4]   2> 4546358 T12012 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 4546363 T12012 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 4546364 T12012 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 4546372 T12012 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 4546373 T12012 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 4546378 T12012 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 4546379 T12012 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 4546386 T12012 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 4546386 T12012 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 4546396 T12012 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 4546396 T12012 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 4546400 T12012 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 4546401 T12012 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 4546406 T12012 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 4546407 T12012 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 4546414 T12012 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 4546414 T12012 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 4546421 T12012 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 4546422 T12012 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 4548312 T12012 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 4548320 T12012 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52303
   [junit4]   2> 4548321 T12012 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 4548321 T12012 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 4548323 T12012 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-002
   [junit4]   2> 4548323 T12012 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-002/'
   [junit4]   2> 4548371 T12012 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-002/solr.xml
   [junit4]   2> 4548386 T12012 oasc.CoreContainer.<init> New CoreContainer 1510464161
   [junit4]   2> 4548386 T12012 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-002/]
   [junit4]   2> 4548387 T12012 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 4548387 T12012 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 4548388 T12012 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 4548388 T12012 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 4548388 T12012 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 4548389 T12012 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 4548389 T12012 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 4548389 T12012 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 4548390 T12012 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 4548390 T12012 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
   [junit4]   2> 4548391 T12012 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 4548391 T12012 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 4548391 T12012 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 4548392 T12012 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52300/solr
   [junit4]   2> 4548392 T12012 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 4548393 T12012 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 4548394 T12012 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4548397 T12032 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6dbfe4dd name:ZooKeeperConnection Watcher:127.0.0.1:52300 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4548397 T12012 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4548398 T12012 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 4548404 T12012 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4548405 T12034 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7d04310 name:ZooKeeperConnection Watcher:127.0.0.1:52300/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4548405 T12012 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4548408 T12012 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 4548417 T12012 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 4548429 T12012 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 4548446 T12012 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 4548458 T12012 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 4548469 T12012 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 4548473 T12012 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52303__n%2Fdf
   [junit4]   2> 4548475 T12012 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52303__n%2Fdf
   [junit4]   2> 4548484 T12012 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 4548490 T12012 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 4548496 T12012 oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 4548501 T12012 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:52303__n%2Fdf
   [junit4]   2> 4548501 T12012 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 4548508 T12012 oasc.Overseer.start Overseer (id=92373123284140035-127.0.0.1:52303__n%2Fdf-n_0000000000) starting
   [junit4]   2> 4548516 T12012 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 4548543 T12012 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
   [junit4]   2> 4548546 T12035 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 4548549 T12036 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 4548550 T12012 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 4548555 T12012 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 4548557 T12012 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 4548572 T12038 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 4548572 T12038 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 4548574 T12039 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 4548578 T12035 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:52303/_n/df",
   [junit4]   2> 	  "node_name":"127.0.0.1:52303__n%2Fdf",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 4548578 T12035 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 4548578 T12035 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 4548580 T12038 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 4548584 T12039 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> 4549582 T12038 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 4549583 T12038 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 4549586 T12038 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 4549586 T12038 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 4549590 T12038 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 4549590 T12038 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-002/collection1/'
   [junit4]   2> 4549592 T12038 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-002/collection1/lib/.svn/' to classloader
   [junit4]   2> 4549592 T12038 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-002/collection1/lib/classes/' to classloader
   [junit4]   2> 4549593 T12038 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-002/collection1/lib/README' to classloader
   [junit4]   2> 4549684 T12038 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0
   [junit4]   2> 4549695 T12038 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 4549698 T12038 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 4549706 T12038 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 4549848 T12038 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 4549850 T12038 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 4549851 T12038 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 4549857 T12038 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 4549898 T12038 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 4549898 T12038 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 4549899 T12038 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-002/collection1/, dataDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-001/control/data/
   [junit4]   2> 4549900 T12038 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3992b2b
   [junit4]   2> 4549900 T12038 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-001/control/data
   [junit4]   2> 4549900 T12038 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-001/control/data/index/
   [junit4]   2> 4549901 T12038 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-001/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 4549901 T12038 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-001/control/data/index
   [junit4]   2> 4549901 T12038 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=39, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 4549903 T12038 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1ec82677 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@10c6a6ab),segFN=segments_1,generation=1}
   [junit4]   2> 4549903 T12038 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 4549907 T12038 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 4549907 T12038 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 4549908 T12038 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 4549908 T12038 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 4549908 T12038 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 4549909 T12038 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 4549909 T12038 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 4549910 T12038 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 4549910 T12038 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 4549910 T12038 oasc.RequestHandlers.initHandlersFromConfig created /update: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4549911 T12038 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4549912 T12038 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4549912 T12038 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4549913 T12038 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 4549914 T12038 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 4549914 T12038 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 4549914 T12038 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 4549915 T12038 oasc.RequestHandlers.initHandlersFromConfig WARN Multiple requestHandler registered to the same name: /update ignoring: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4549915 T12038 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 4549916 T12038 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 4549916 T12038 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 4549917 T12038 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 4549926 T12038 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4549927 T12038 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4549928 T12038 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4549929 T12038 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4549930 T12038 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4549934 T12038 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 4549934 T12038 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 4549935 T12038 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=18, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 4549936 T12038 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1ec82677 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@10c6a6ab),segFN=segments_1,generation=1}
   [junit4]   2> 4549936 T12038 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 4549936 T12038 oass.SolrIndexSearcher.<init> Opening Searcher@113817c6[collection1] main
   [junit4]   2> 4549937 T12038 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 4549940 T12038 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 4549941 T12038 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 4549942 T12038 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 4549942 T12038 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 4549942 T12038 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 4549944 T12038 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 4549945 T12038 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 4549946 T12038 oascc.SolrZkClient.makePath makePath: /configs/conf1/_rest_managed.json
   [junit4]   2> 4549951 T12038 oasr.ManagedResourceStorage$ZooKeeperStorageIO$1.close Wrote 38 bytes to new znode /configs/conf1/_rest_managed.json
   [junit4]   2> 4549955 T12038 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 4549956 T12038 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 4549963 T12038 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 4549964 T12040 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@113817c6[collection1] main{UninvertingDirectoryReader()}
   [junit4]   2> 4549965 T12043 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52303/_n/df collection:control_collection shard:shard1
   [junit4]   2> 4549968 T12012 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 4549969 T12012 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 4549970 T12012 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 4549973 T12012 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4549977 T12043 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 4549978 T12045 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@401a8220 name:ZooKeeperConnection Watcher:127.0.0.1:52300/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4549979 T12012 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4549979 T12012 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 4549981 T12012 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 4549986 T12012 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 4550036 T12043 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 4550040 T12039 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 4550045 T12043 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 4550045 T12043 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C4216 name=collection1 org.apache.solr.core.SolrCore@4eb19c62 url=http://127.0.0.1:52303/_n/df/collection1 node=127.0.0.1:52303__n%2Fdf C4216_STATE=coll:control_collection core:collection1 props:{core=collection1, base_url=http://127.0.0.1:52303/_n/df, node_name=127.0.0.1:52303__n%2Fdf, state=down}
   [junit4]   2> 4550045 T12043 C4216 P52303 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52303/_n/df/collection1/
   [junit4]   2> 4550046 T12043 C4216 P52303 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 4550046 T12043 C4216 P52303 oasc.SyncStrategy.syncToMe http://127.0.0.1:52303/_n/df/collection1/ has no replicas
   [junit4]   2> 4550046 T12043 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52303/_n/df/collection1/ shard1
   [junit4]   2> 4550046 T12043 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 4550069 T12039 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 4550090 T12039 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> 4550092 T12046 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> 4550176 T12043 oasc.ZkController.register We are http://127.0.0.1:52303/_n/df/collection1/ and leader is http://127.0.0.1:52303/_n/df/collection1/
   [junit4]   2> 4550178 T12043 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52303/_n/df
   [junit4]   2> 4550178 T12043 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 4550179 T12043 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 4550179 T12043 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 4550186 T12039 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 4550204 T12035 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:52303/_n/df",
   [junit4]   2> 	  "node_name":"127.0.0.1:52303__n%2Fdf",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 4550329 T12046 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> 4550329 T12039 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> 4552201 T12012 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 4552202 T12012 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 4552211 T12012 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52307
   [junit4]   2> 4552215 T12012 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 4552215 T12012 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 4552216 T12012 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-003
   [junit4]   2> 4552217 T12012 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-003/'
   [junit4]   2> 4552254 T12012 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-003/solr.xml
   [junit4]   2> 4552268 T12012 oasc.CoreContainer.<init> New CoreContainer 269979516
   [junit4]   2> 4552268 T12012 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-003/]
   [junit4]   2> 4552268 T12012 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 4552269 T12012 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 4552269 T12012 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 4552270 T12012 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 4552270 T12012 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 4552270 T12012 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 4552271 T12012 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 4552271 T12012 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 4552271 T12012 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 4552272 T12012 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
   [junit4]   2> 4552272 T12012 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 4552272 T12012 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 4552273 T12012 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 4552273 T12012 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52300/solr
   [junit4]   2> 4552274 T12012 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 4552274 T12012 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 4552277 T12012 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4552279 T12057 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@779ba864 name:ZooKeeperConnection Watcher:127.0.0.1:52300 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4552279 T12012 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4552280 T12012 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 4552284 T12012 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4552286 T12059 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e3a1f74 name:ZooKeeperConnection Watcher:127.0.0.1:52300/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4552287 T12012 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4552309 T12012 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 4553326 T12012 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52307__n%2Fdf
   [junit4]   2> 4553330 T12012 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52307__n%2Fdf
   [junit4]   2> 4553349 T12012 oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 4553361 T12061 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 4553362 T12061 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 4553364 T12039 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 4553364 T12061 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 4553371 T12035 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:52307/_n/df",
   [junit4]   2> 	  "node_name":"127.0.0.1:52307__n%2Fdf",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 4553371 T12035 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 4553372 T12035 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 4553381 T12039 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> 4553381 T12046 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> 4553383 T12060 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> 4554367 T12061 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 4554368 T12061 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 4554371 T12061 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 4554371 T12061 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 4554378 T12061 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 4554378 T12061 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-003/collection1/'
   [junit4]   2> 4554379 T12061 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-003/collection1/lib/.svn/' to classloader
   [junit4]   2> 4554380 T12061 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-003/collection1/lib/classes/' to classloader
   [junit4]   2> 4554381 T12061 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-003/collection1/lib/README' to classloader
   [junit4]   2> 4554449 T12061 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0
   [junit4]   2> 4554459 T12061 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 4554463 T12061 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 4554471 T12061 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 4554620 T12061 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 4554621 T12061 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 4554623 T12061 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 4554628 T12061 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 4554691 T12061 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 4554691 T12061 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 4554691 T12061 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-003/collection1/, dataDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-001/jetty1/
   [junit4]   2> 4554692 T12061 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3992b2b
   [junit4]   2> 4554692 T12061 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-001/jetty1
   [junit4]   2> 4554692 T12061 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-001/jetty1/index/
   [junit4]   2> 4554693 T12061 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-001/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 4554694 T12061 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-001/jetty1/index
   [junit4]   2> 4554694 T12061 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=39, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 4554695 T12061 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@24095c87 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@684ae415),segFN=segments_1,generation=1}
   [junit4]   2> 4554695 T12061 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 4554703 T12061 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 4554704 T12061 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 4554705 T12061 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 4554705 T12061 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 4554705 T12061 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 4554705 T12061 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 4554706 T12061 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 4554707 T12061 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 4554707 T12061 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 4554708 T12061 oasc.RequestHandlers.initHandlersFromConfig created /update: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4554709 T12061 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4554710 T12061 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4554711 T12061 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4554712 T12061 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 4554712 T12061 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 4554712 T12061 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 4554713 T12061 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 4554713 T12061 oasc.RequestHandlers.initHandlersFromConfig WARN Multiple requestHandler registered to the same name: /update ignoring: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4554714 T12061 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 4554714 T12061 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 4554715 T12061 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 4554715 T12061 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 4554723 T12061 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4554724 T12061 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4554725 T12061 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4554727 T12061 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4554728 T12061 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4554731 T12061 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 4554731 T12061 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 4554731 T12061 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=18, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 4554732 T12061 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@24095c87 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@684ae415),segFN=segments_1,generation=1}
   [junit4]   2> 4554733 T12061 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 4554733 T12061 oass.SolrIndexSearcher.<init> Opening Searcher@432f64fe[collection1] main
   [junit4]   2> 4554733 T12061 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 4554735 T12061 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 4554736 T12061 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 4554736 T12061 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 4554737 T12061 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 4554737 T12061 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 4554740 T12061 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json
   [junit4]   2> 4554740 T12061 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 4554740 T12061 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed
   [junit4]   2> 4554741 T12061 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 4554752 T12062 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@432f64fe[collection1] main{UninvertingDirectoryReader()}
   [junit4]   2> 4554759 T12061 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 4554763 T12065 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52307/_n/df collection:collection1 shard:shard2
   [junit4]   2> 4554767 T12012 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 4554767 T12012 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 4554770 T12065 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 4554791 T12065 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 4554796 T12065 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 4554797 T12065 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C4217 name=collection1 org.apache.solr.core.SolrCore@47366faa url=http://127.0.0.1:52307/_n/df/collection1 node=127.0.0.1:52307__n%2Fdf C4217_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=http://127.0.0.1:52307/_n/df, node_name=127.0.0.1:52307__n%2Fdf, state=down}
   [junit4]   2> 4554797 T12065 C4217 P52307 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52307/_n/df/collection1/
   [junit4]   2> 4554797 T12065 C4217 P52307 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 4554798 T12065 C4217 P52307 oasc.SyncStrategy.syncToMe http://127.0.0.1:52307/_n/df/collection1/ has no replicas
   [junit4]   2> 4554798 T12065 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52307/_n/df/collection1/ shard2
   [junit4]   2> 4554798 T12065 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 4554800 T12039 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 4554819 T12039 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 4554932 T12039 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> 4554933 T12060 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> 4554936 T12046 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> 4554974 T12065 oasc.ZkController.register We are http://127.0.0.1:52307/_n/df/collection1/ and leader is http://127.0.0.1:52307/_n/df/collection1/
   [junit4]   2> 4554974 T12065 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52307/_n/df
   [junit4]   2> 4554974 T12065 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 4554975 T12065 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 4554975 T12065 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 4554978 T12039 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 4554986 T12035 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:52307/_n/df",
   [junit4]   2> 	  "node_name":"127.0.0.1:52307__n%2Fdf",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 4555100 T12039 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> 4555101 T12046 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> 4555102 T12060 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> 4556619 T12012 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 4556620 T12012 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 4556626 T12012 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52310
   [junit4]   2> 4556629 T12012 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 4556630 T12012 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 4556630 T12012 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-004
   [junit4]   2> 4556631 T12012 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-004/'
   [junit4]   2> 4556684 T12012 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-004/solr.xml
   [junit4]   2> 4556708 T12012 oasc.CoreContainer.<init> New CoreContainer 1910436516
   [junit4]   2> 4556710 T12012 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-004/]
   [junit4]   2> 4556712 T12012 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 4556712 T12012 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 4556714 T12012 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 4556715 T12012 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 4556715 T12012 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 4556716 T12012 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 4556717 T12012 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 4556718 T12012 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 4556719 T12012 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 4556719 T12012 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
   [junit4]   2> 4556721 T12012 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 4556721 T12012 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 4556721 T12012 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 4556721 T12012 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52300/solr
   [junit4]   2> 4556722 T12012 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 4556722 T12012 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 4556724 T12012 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4556727 T12076 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@34cf6703 name:ZooKeeperConnection Watcher:127.0.0.1:52300 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4556728 T12012 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4556729 T12012 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 4556735 T12012 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4556737 T12078 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5d39d08a name:ZooKeeperConnection Watcher:127.0.0.1:52300/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4556738 T12012 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4556757 T12012 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 4557769 T12012 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52310__n%2Fdf
   [junit4]   2> 4557772 T12012 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52310__n%2Fdf
   [junit4]   2> 4557786 T12012 oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 4557796 T12080 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 4557797 T12080 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 4557799 T12039 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 4557799 T12080 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 4557806 T12035 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:52310/_n/df",
   [junit4]   2> 	  "node_name":"127.0.0.1:52310__n%2Fdf",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 4557806 T12035 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 4557806 T12035 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 4557815 T12046 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> 4557815 T12079 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> 4557815 T12039 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> 4557816 T12060 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> 4558801 T12080 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 4558802 T12080 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 4558806 T12080 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 4558807 T12080 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 4558816 T12080 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 4558816 T12080 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-004/collection1/'
   [junit4]   2> 4558824 T12080 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-004/collection1/lib/.svn/' to classloader
   [junit4]   2> 4558826 T12080 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-004/collection1/lib/classes/' to classloader
   [junit4]   2> 4558827 T12080 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-004/collection1/lib/README' to classloader
   [junit4]   2> 4558894 T12080 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0
   [junit4]   2> 4558906 T12080 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 4558911 T12080 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 4558916 T12080 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 4559061 T12080 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 4559062 T12080 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 4559064 T12080 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 4559070 T12080 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 4559136 T12080 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 4559136 T12080 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 4559136 T12080 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-004/collection1/, dataDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-001/jetty2/
   [junit4]   2> 4559137 T12080 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3992b2b
   [junit4]   2> 4559137 T12080 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-001/jetty2
   [junit4]   2> 4559138 T12080 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-001/jetty2/index/
   [junit4]   2> 4559138 T12080 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-001/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 4559139 T12080 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-001/jetty2/index
   [junit4]   2> 4559139 T12080 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=39, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 4559139 T12080 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@5c9a39d lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@464cf8fb),segFN=segments_1,generation=1}
   [junit4]   2> 4559140 T12080 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 4559146 T12080 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 4559147 T12080 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 4559147 T12080 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 4559148 T12080 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 4559148 T12080 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 4559148 T12080 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 4559149 T12080 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 4559149 T12080 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 4559150 T12080 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 4559150 T12080 oasc.RequestHandlers.initHandlersFromConfig created /update: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4559150 T12080 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4559151 T12080 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4559151 T12080 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4559152 T12080 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 4559153 T12080 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 4559153 T12080 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 4559154 T12080 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 4559154 T12080 oasc.RequestHandlers.initHandlersFromConfig WARN Multiple requestHandler registered to the same name: /update ignoring: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 4559155 T12080 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 4559156 T12080 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 4559156 T12080 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 4559157 T12080 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 4559173 T12080 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4559176 T12080 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4559180 T12080 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4559182 T12080 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4559183 T12080 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 4559186 T12080 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 4559186 T12080 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 4559186 T12080 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=18, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 4559187 T12080 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@5c9a39d lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@464cf8fb),segFN=segments_1,generation=1}
   [junit4]   2> 4559187 T12080 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 4559188 T12080 oass.SolrIndexSearcher.<init> Opening Searcher@7e7ab25f[collection1] main
   [junit4]   2> 4559188 T12080 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 4559192 T12080 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 4559192 T12080 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 4559194 T12080 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 4559194 T12080 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 4559196 T12080 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 4559199 T12080 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json
   [junit4]   2> 4559199 T12080 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 4559199 T12080 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed
   [junit4]   2> 4559199 T12080 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 4559203 T12081 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7e7ab25f[collection1] main{UninvertingDirectoryReader()}
   [junit4]   2> 4559209 T12080 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 4559212 T12084 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52310/_n/df collection:collection1 shard:shard1
   [junit4]   2> 4559213 T12012 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 4559214 T12012 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 4559215 T12084 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 4559228 T12084 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 4559232 T12039 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 4559233 T12084 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 4559233 T12084 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C4218 name=collection1 org.apache.solr.core.SolrCore@4ec913f3 url=http://127.0.0.1:52310/_n/df/collection1 node=127.0.0.1:52310__n%2Fdf C4218_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=http://127.0.0.1:52310/_n/df, node_name=127.0.0.1:52310__n%2Fdf, state=down}
   [junit4]   2> 4559234 T12084 C4218 P52310 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52310/_n/df/collection1/
   [junit4]   2> 4559235 T12084 C4218 P52310 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 4559235 T12084 C4218 P52310 oasc.SyncStrategy.syncToMe http://127.0.0.1:52310/_n/df/collection1/ has no replicas
   [junit4]   2> 4559235 T12084 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52310/_n/df/collection1/ shard1
   [junit4]   2> 4559235 T12084 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 4559264 T12039 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 4559370 T12079 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> 4559370 T12060 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> 4559372 T12046 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> 4559373 T12039 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> 4559411 T12084 oasc.ZkController.register We are http://127.0.0.1:52310/_n/df/collection1/ and leader is http://127.0.0.1:52310/_n/df/collection1/
   [junit4]   2> 4559413 T12084 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52310/_n/df
   [junit4]   2> 4559414 T12084 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 4559414 T12084 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 4559416 T12084 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 4559429 T12039 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 4559434 T12035 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:52310/_n/df",
   [junit4]   2> 	  "node_name":"127.0.0.1:52310__n%2Fdf",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 4559544 T12039 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> 4559545 T12079 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> 4559545 T12046 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> 4559546 T12060 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> 4561180 T12012 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
   [junit4]   2> 4561181 T12012 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 4561189 T12012 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52313
   [junit4]   2> 4561191 T12012 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 4561192 T12012 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 4561192 T12012 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-005
   [junit4]   2> 4561193 T12012 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-005/'
   [junit4]   2> 4561241 T12012 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-005/solr.xml
   [junit4]   2> 4561256 T12012 oasc.CoreContainer.<init> New CoreContainer 2048510009
   [junit4]   2> 4561256 T12012 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001/tempDir-005/]
   [junit4]   2> 4561257 T12012 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 4561257 T12012 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 4561258 T12012 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 4561258 T12012 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 4561258 T12012 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 4561259 T12012 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 4561260 T12012 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 4561260 T12012 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 4561260 T12012 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 4561260 T12012 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
   [junit4]   2> 4561261 T12012 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 4561262 T12012 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 4561262 T12012 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 4561263 T12012 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52300/solr
   [junit4]   2> 4561263 T12012 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 4561263 T12012 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 4561264 T12012 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4561269 T12095 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10ea7f0d name:ZooKeeperConnection Watcher:127.0.0.1:52300 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4561270 T12012 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4561270 T12012 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 4561276 T12012 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 4561278 T12097 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13f580fb name:ZooKeeperConnection Watcher:127.0.0.1:52300/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 4561278 T12012 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 4561303 T12012 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 4562314 T12012 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52313__n%2Fdf
   [junit4]   2> 4562318 T12012 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52313__n%2Fdf
   [junit4]   2> 4562337 T12012 oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 4562350 T12099 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 4562351 T12099 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 4562353 T12099 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 4562353 T12039 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 4562359 T12035 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:52313/_n/df",
   [junit4]   2> 	  "node_name":"127.0.0.1:52313__n%2Fdf",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 4562359 T12035 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 4562359 T12035 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 4562369 T12079 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 4562369 T12060 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 4562369 T

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

	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 4787819 T12012 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.OverseerStatusTest-5A92393B9AB95AF1-001
   [junit4]   2> 241635 T12011 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
   [junit4]   2> NOTE: test params are: codec=Lucene46, sim=DefaultSimilarity, locale=de, timezone=AST
   [junit4]   2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.8.0_20 (64-bit)/cpus=2,threads=1,free=32526704,total=236658688
   [junit4]   2> NOTE: All tests run in this JVM: [TestRecovery, DistributedTermsComponentTest, CachingDirectoryFactoryTest, TestSolrXmlPersistor, HardAutoCommitTest, OpenExchangeRatesOrgProviderTest, TestDFRSimilarityFactory, TestPostingsSolrHighlighter, TestSerializedLuceneMatchVersion, MinimalSchemaTest, TestNRTOpen, SearchHandlerTest, TestComplexPhraseQParserPlugin, SliceStateTest, TestCollationFieldDocValues, TestRealTimeGet, UUIDFieldTest, ZkCLITest, SpatialFilterTest, TestDistribDocBasedVersion, TestReloadAndDeleteDocs, TestJoin, MBeansHandlerTest, IndexBasedSpellCheckerTest, TestRestManager, ShardRoutingTest, TestCloudPivotFacet, TestQuerySenderNoQuery, FunctionTest, PrimitiveFieldTypeTest, HdfsUnloadDistributedZkTest, SolrPluginUtilsTest, TestStressLucene, JSONWriterTest, AtomicUpdatesTest, TestExpandComponent, TestTolerantSearch, DeleteInactiveReplicaTest, SortByFunctionTest, TestSchemaNameResource, ClusterStateUpdateTest, TestDistributedMissingSort, BasicDistributedZk2Test, DistributedSuggestComponentTest, TestFuzzyAnalyzedSuggestions, DocValuesMissingTest, TestFaceting, XmlUpdateRequestHandlerTest, DistribDocExpirationUpdateProcessorTest, OverseerTest, TestTrie, TestDistributedSearch, EnumFieldTest, ScriptEngineTest, UnloadDistributedZkTest, TestCollapseQParserPlugin, HighlighterMaxOffsetTest, UUIDUpdateProcessorFallbackTest, TestManagedSynonymFilterFactory, TestFieldSortValues, TestCoreDiscovery, HdfsWriteToMultipleCollectionsTest, ShardRoutingCustomTest, RemoteQueryErrorTest, TestSortingResponseWriter, BadCopyFieldTest, SolrCmdDistributorTest, NotRequiredUniqueKeyTest, DocValuesTest, TestStandardQParsers, LukeRequestHandlerTest, DistributedIntervalFacetingTest, CollectionsAPIDistributedZkTest, ClusterStateTest, OutputWriterTest, TestReplicationHandler, TestHighFrequencyDictionaryFactory, MergeStrategyTest, TermsComponentTest, TestMissingGroups, BadIndexSchemaTest, HdfsBasicDistributedZkTest, DistributedQueryElevationComponentTest, AnalyticsQueryTest, TestOmitPositions, SynonymTokenizerTest, TestUpdate, TestLFUCache, CoreAdminCreateDiscoverTest, TestSearcherReuse, HdfsRecoveryZkTest, TestFastWriter, BinaryUpdateRequestHandlerTest, ExpressionTest, CustomCollectionTest, CoreAdminRequestStatusTest, FastVectorHighlighterTest, DirectUpdateHandlerTest, TestLazyCores, TestRemoteStreaming, TestManagedResource, TestDistributedGrouping, TestRangeQuery, TestQuerySenderListener, TestWriterPerf, LegacyHTMLStripCharFilterTest, TestReplicationHandlerBackup, TestCSVLoader, PluginInfoTest, NoFacetTest, TestStressRecovery, SpellPossibilityIteratorTest, TestDocBasedVersionConstraints, TestSolrCoreProperties, OverriddenZkACLAndCredentialsProvidersTest, TestZkChroot, DocumentAnalysisRequestHandlerTest, DistributedSpellCheckComponentTest, TestExceedMaxTermLength, SolrCoreCheckLockOnStartupTest, TestCloudManagedSchemaConcurrent, StressHdfsTest, PolyFieldTest, TestCollectionAPI, TestSort, TestFastOutputStream, TestSolr4Spatial, JsonLoaderTest, TestReload, SpellingQueryConverterTest, TestCharFilters, ResponseLogComponentTest, HttpPartitionTest, CoreAdminHandlerTest, TestComponentsName, IndexSchemaRuntimeFieldTest, TestCloudInspectUtil, HdfsLockFactoryTest, LoggingHandlerTest, TestPHPSerializedResponseWriter, TestExtendedDismaxParser, WordBreakSolrSpellCheckerTest, TestIndexSearcher, TestCollationField, TestAnalyzeInfixSuggestions, TestFiltering, DebugComponentTest, TestFileDictionaryLookup, AliasIntegrationTest, TestRecoveryHdfs, ResponseHeaderTest, URLClassifyProcessorTest, DistanceFunctionTest, PeerSyncTest, TestShortCircuitedRequests, TestWordDelimiterFilterFactory, TestRandomFaceting, TestSolrIndexConfig, TestIndexingPerformance, TestBinaryResponseWriter, DistributedDebugComponentTest, DirectSolrSpellCheckerTest, DateRangeFieldTest, ZkSolrClientTest, TestSchemaSimilarityResource, OverseerCollectionProcessorTest, TestDefaultSimilarityFactory, TestBadConfig, AbstractAnalyticsFacetTest, SolrInfoMBeanTest, SuggesterTest, DateFieldTest, ExternalFileFieldSortTest, BadComponentTest, TestCustomSort, TestStressReorder, FileUtilsTest, CursorMarkTest, UniqFieldsUpdateProcessorFactoryTest, TestSolrXmlPersistence, HdfsBasicDistributedZk2Test, PathHierarchyTokenizerFactoryTest, SignatureUpdateProcessorFactoryTest, TermVectorComponentDistributedTest, MoreLikeThisHandlerTest, TestValueSourceCache, MigrateRouteKeyTest, TestLMDirichletSimilarityFactory, TestDocumentBuilder, TestElisionMultitermQuery, TestIntervalFaceting, TestLMJelinekMercerSimilarityFactory, TestFieldResource, TestRandomMergePolicy, BasicZkTest, DeleteShardTest, TestLuceneMatchVersion, TestCoreContainer, ZkNodePropsTest, TestRequestStatusCollectionAPI, TestGroupingSearch, TestManagedStopFilterFactory, TestSolrDeletionPolicy2, TestIBSimilarityFactory, TestSchemaVersionResource, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, SyncSliceTest, OpenCloseCoreStressTest, LeaderElectionIntegrationTest, RecoveryZkTest, FullSolrCloudDistribCmdsTest, LeaderElectionTest, TestRandomDVFaceting, AutoCommitTest, TestHashPartitioner, ZkControllerTest, TestMultiCoreConfBootstrap, TestStressVersions, SimpleFacetsTest, SolrCoreTest, StatsComponentTest, SpellCheckComponentTest, QueryElevationComponentTest, ConvertedLegacyTest, TestFunctionQuery, BasicFunctionalityTest, HighlighterTest, SoftAutoCommitTest, ShowFileRequestHandlerTest, CurrencyFieldOpenExchangeTest, CurrencyFieldXmlFileTest, SolrIndexSplitterTest, SimplePostToolTest, AnalysisAfterCoreReloadTest, SpellCheckCollatorTest, SuggesterFSTTest, SolrRequestParserTest, TestFoldingMultitermQuery, SuggesterTSTTest, SuggesterWFSTTest, NoCacheHeaderTest, SchemaVersionSpecificBehaviorTest, TestPseudoReturnFields, FieldMutatingUpdateProcessorTest, TestAtomicUpdateErrorCases, QueryEqualityTest, DirectUpdateHandlerOptimizeTest, DefaultValueUpdateProcessorTest, StatelessScriptUpdateProcessorFactoryTest, DocValuesMultiTest, TestSolrDeletionPolicy1, XsltUpdateRequestHandlerTest, CacheHeaderTest, TestSurroundQueryParser, DisMaxRequestHandlerTest, TestQueryUtils, StandardRequestHandlerTest, TestReversedWildcardFilterFactory, TestQueryTypes, FileBasedSpellCheckerTest, RequestHandlersTest, DocumentBuilderTest, TermVectorComponentTest, RequiredFieldsTest, FieldAnalysisRequestHandlerTest, TestSolrQueryParser, TestArbitraryIndexDir, RegexBoostProcessorTest, IndexSchemaTest, TestJmxIntegration, ReturnFieldsTest, UpdateRequestProcessorFactoryTest, TestCSVResponseWriter, QueryParsingTest, TestAnalyzedSuggestions, TestPartialUpdateDeduplication, PingRequestHandlerTest, CSVRequestHandlerTest, CoreContainerCoreInitFailuresTest, HighlighterConfigTest, SOLR749Test, UpdateParamsTest, AlternateDirectoryTest, CopyFieldTest, SolrIndexConfigTest, TestMergePolicyConfig, MultiTermTest, SampleTest, TestDocSet, TestBinaryField, TestSearchPerf, NumericFieldsTest, TestConfig, DirectSolrConnectionTest, TestPhraseSuggestions, TestCodecSupport, TestXIncludeConfig, EchoParamsTest, TestSweetSpotSimilarityFactory, TestPerFieldSimilarity, TestBM25SimilarityFactory, TestJmxMonitoredMap, TimeZoneUtilsTest, ResourceLoaderTest, TestFastLRUCache, DateMathParserTest, ChaosMonkeyNothingIsSafeTest, PreAnalyzedFieldTest, TestSystemIdResolver, PrimUtilsTest, TestSuggestSpellingConverter, DOMUtilTest, RAMDirectoryFactoryTest, TestSolrJ, TestLRUCache, TestUtils, SystemInfoHandlerTest, CircularListTest, TestRTGBase, CursorPagingTest, SolrTestCaseJ4Test, TestCursorMarkWithoutUniqueKey, TestHighlightDedupGrouping, AbstractAnalyticsStatsTest, FieldFacetExtrasTest, FieldFacetTest, QueryFacetTest, RangeFacetTest, AssignTest, AsyncMigrateRouteKeyTest, CollectionsAPIAsyncDistributedZkTest, ConnectionManagerTest, DeleteLastCustomShardedReplicaTest, DeleteReplicaTest, DistribCursorPagingTest, MultiThreadedOCPTest, OutOfBoxZkACLAndCredentialsProvidersTest, OverseerRolesTest, OverseerStatusTest]
   [junit4] Completed in 241.94s, 1 test, 1 error <<< FAILURES!

[...truncated 263 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:492: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:472: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:60: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/extra-targets.xml:39: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/common-build.xml:494: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1343: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:958: There were test failures: 434 suites, 1801 tests, 1 error, 49 ignored (22 assumptions)

Total time: 142 minutes 9 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 64bit/jdk1.8.0 -XX:+UseCompressedOops -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any