lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject [JENKINS] Lucene-Solr-NightlyTests-4.x - Build # 569 - Still Failing
Date Thu, 03 Jul 2014 02:45:26 GMT
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-4.x/569/

2 tests failed.
REGRESSION:  org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.testDistribSearch

Error Message:
IOException occured when talking to server at: http://127.0.0.1:17323/collection1

Stack Trace:
org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:17323/collection1
	at __randomizedtesting.SeedInfo.seed([EFDCB4F4D6D1BBF:8F1B45573A327B83]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:566)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:210)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:206)
	at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:91)
	at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
	at org.apache.solr.cloud.CloudInspectUtil.compareResults(CloudInspectUtil.java:223)
	at org.apache.solr.cloud.CloudInspectUtil.compareResults(CloudInspectUtil.java:165)
	at org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.testIndexingBatchPerRequestWithHttpSolrServer(FullSolrCloudDistribCmdsTest.java:415)
	at org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.doTest(FullSolrCloudDistribCmdsTest.java:145)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:865)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java: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)
Caused by: java.net.SocketException: Broken pipe
	at java.net.SocketOutputStream.socketWrite0(Native Method)
	at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:113)
	at java.net.SocketOutputStream.write(SocketOutputStream.java:159)
	at org.apache.http.impl.io.AbstractSessionOutputBuffer.flushBuffer(AbstractSessionOutputBuffer.java:159)
	at org.apache.http.impl.io.AbstractSessionOutputBuffer.writeLine(AbstractSessionOutputBuffer.java:258)
	at org.apache.http.impl.io.HttpRequestWriter.writeHeadLine(HttpRequestWriter.java:59)
	at org.apache.http.impl.io.HttpRequestWriter.writeHeadLine(HttpRequestWriter.java:46)
	at org.apache.http.impl.io.AbstractMessageWriter.write(AbstractMessageWriter.java:109)
	at org.apache.http.impl.AbstractHttpClientConnection.sendRequestHeader(AbstractHttpClientConnection.java:254)
	at org.apache.http.impl.conn.DefaultClientConnection.sendRequestHeader(DefaultClientConnection.java:270)
	at org.apache.http.impl.conn.ManagedClientConnectionImpl.sendRequestHeader(ManagedClientConnectionImpl.java:209)
	at org.apache.http.protocol.HttpRequestExecutor.doSendRequest(HttpRequestExecutor.java:203)
	at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:121)
	at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:682)
	at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:486)
	at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:863)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:57)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:452)
	... 50 more


REGRESSION:  org.apache.solr.cloud.RecoveryZkTest.testDistribSearch

Error Message:
shard1 is not consistent.  Got 78 from http://127.0.0.1:50417/x_/h/collection1lastClient and got 46 from http://127.0.0.1:54345/x_/h/collection1

Stack Trace:
java.lang.AssertionError: shard1 is not consistent.  Got 78 from http://127.0.0.1:50417/x_/h/collection1lastClient and got 46 from http://127.0.0.1:54345/x_/h/collection1
	at __randomizedtesting.SeedInfo.seed([EFDCB4F4D6D1BBF:8F1B45573A327B83]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.RecoveryZkTest.doTest(RecoveryZkTest.java:123)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:865)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java: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 12007 lines...]
   [junit4] Suite: org.apache.solr.cloud.RecoveryZkTest
   [junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/init-core-data-001
   [junit4]   2> 3000754 T455281 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (true)
   [junit4]   2> 3000755 T455281 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /x_/h
   [junit4]   2> 3000761 T455281 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> 3000762 T455281 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 3000763 T455282 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 3000863 T455281 oasc.ZkTestServer.run start zk server on port:15150
   [junit4]   2> 3000865 T455281 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3000873 T455288 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6be3d3a0 name:ZooKeeperConnection Watcher:127.0.0.1:15150 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3000873 T455281 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3000874 T455281 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 3000888 T455281 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3000890 T455290 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4019eb name:ZooKeeperConnection Watcher:127.0.0.1:15150/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3000890 T455281 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3000891 T455281 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 3000895 T455281 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 3000905 T455281 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 3000907 T455281 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 3000909 T455281 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 3000910 T455281 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 3000926 T455281 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
   [junit4]   2> 3000927 T455281 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 3001030 T455281 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 3001031 T455281 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 3001034 T455281 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 3001034 T455281 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 3001042 T455281 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 3001043 T455281 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 3001045 T455281 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 3001045 T455281 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 3001048 T455281 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 3001048 T455281 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 3001050 T455281 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 3001051 T455281 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 3001059 T455281 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 3001059 T455281 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 3001061 T455281 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 3001062 T455281 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 3001065 T455281 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 3001065 T455281 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 3002138 T455281 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 3002148 T455281 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:50360
   [junit4]   2> 3002148 T455281 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 3002148 T455281 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 3002149 T455281 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-002
   [junit4]   2> 3002149 T455281 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-002/'
   [junit4]   2> 3002178 T455281 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-002/solr.xml
   [junit4]   2> 3002227 T455281 oasc.CoreContainer.<init> New CoreContainer 786566782
   [junit4]   2> 3002228 T455281 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-002/]
   [junit4]   2> 3002229 T455281 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 3002229 T455281 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 3002229 T455281 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 3002229 T455281 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 3002230 T455281 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 3002230 T455281 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 3002230 T455281 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 3002230 T455281 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 3002231 T455281 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 3002231 T455281 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 3002231 T455281 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 3002232 T455281 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 3002232 T455281 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:15150/solr
   [junit4]   2> 3002232 T455281 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 3002233 T455281 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3002235 T455301 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7b258a3d name:ZooKeeperConnection Watcher:127.0.0.1:15150 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3002238 T455281 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3002252 T455281 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3002253 T455303 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@25d66866 name:ZooKeeperConnection Watcher:127.0.0.1:15150/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3002254 T455281 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3002257 T455281 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 3002266 T455281 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 3002274 T455281 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 3002284 T455281 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 3002292 T455281 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 3002294 T455281 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 3002297 T455281 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50360_x_%2Fh
   [junit4]   2> 3002305 T455281 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50360_x_%2Fh
   [junit4]   2> 3002308 T455281 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 3002310 T455281 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 3002323 T455281 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:50360_x_%2Fh
   [junit4]   2> 3002323 T455281 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 3002324 T455281 oasc.Overseer.start Overseer (id=92035692780781571-127.0.0.1:50360_x_%2Fh-n_0000000000) starting
   [junit4]   2> 3002335 T455281 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 3002349 T455305 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 3002349 T455281 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 3002354 T455281 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 3002355 T455281 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 3002356 T455304 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 3002360 T455306 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 3002360 T455306 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 3002361 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3002361 T455306 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 3002362 T455304 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3002362 T455304 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50360/x_/h",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50360_x_%2Fh",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 3002363 T455304 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 3002363 T455304 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 3002365 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3002366 T455303 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> 3003362 T455306 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 3003363 T455306 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 3003363 T455306 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 3003364 T455306 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 3003364 T455306 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 3003364 T455306 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-002/collection1/'
   [junit4]   2> 3003366 T455306 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-002/collection1/lib/README' to classloader
   [junit4]   2> 3003367 T455306 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-002/collection1/lib/classes/' to classloader
   [junit4]   2> 3003368 T455306 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-002/collection1/lib/.svn/' to classloader
   [junit4]   2> 3003433 T455306 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_10
   [junit4]   2> 3003489 T455306 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 3003591 T455306 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 3003600 T455306 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 3003955 T455306 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 3003958 T455306 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 3003960 T455306 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 3003964 T455306 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 3003977 T455306 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 3003977 T455306 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 3003977 T455306 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-002/collection1/, dataDir=./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-001/control/data/
   [junit4]   2> 3003978 T455306 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@61871708
   [junit4]   2> 3003978 T455306 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-001/control/data
   [junit4]   2> 3003979 T455306 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-001/control/data/index/
   [junit4]   2> 3003979 T455306 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-001/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 3003979 T455306 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-001/control/data/index
   [junit4]   2> 3003980 T455306 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=17, maxMergeAtOnceExplicit=20, maxMergedSegmentMB=5.2294921875, floorSegmentMB=0.6162109375, forceMergeDeletesPctAllowed=26.593516805814566, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 3003981 T455306 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@5d397694 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2b9dd26e),segFN=segments_1,generation=1}
   [junit4]   2> 3003981 T455306 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 3003983 T455306 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 3003984 T455306 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 3003984 T455306 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 3003984 T455306 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 3003984 T455306 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 3003985 T455306 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 3003985 T455306 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 3003985 T455306 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 3003985 T455306 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 3003986 T455306 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 3003986 T455306 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 3003986 T455306 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 3003987 T455306 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 3003987 T455306 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 3003987 T455306 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 3003988 T455306 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 3004007 T455306 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 3004012 T455306 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 3004012 T455306 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 3004013 T455306 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=44, maxMergeAtOnceExplicit=42, maxMergedSegmentMB=10.1904296875, floorSegmentMB=1.755859375, forceMergeDeletesPctAllowed=26.26056659028575, segmentsPerTier=38.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.767914023905204
   [junit4]   2> 3004013 T455306 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@5d397694 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2b9dd26e),segFN=segments_1,generation=1}
   [junit4]   2> 3004014 T455306 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 3004014 T455306 oass.SolrIndexSearcher.<init> Opening Searcher@1c86dc30[collection1] main
   [junit4]   2> 3004014 T455306 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 3004015 T455306 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 3004015 T455306 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 3004015 T455306 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 3004016 T455306 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 3004016 T455306 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3004016 T455306 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 3004017 T455306 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3004017 T455306 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 3004017 T455306 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 3004019 T455307 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1c86dc30[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 3004020 T455306 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 3004020 T455310 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50360/x_/h collection:control_collection shard:shard1
   [junit4]   2> 3004020 T455281 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
   [junit4]   2> 3004021 T455281 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 3004021 T455310 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 3004022 T455281 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3004024 T455312 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2a739590 name:ZooKeeperConnection Watcher:127.0.0.1:15150/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3004024 T455281 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3004036 T455281 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 3004039 T455310 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 3004039 T455281 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 3004040 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3004041 T455310 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 3004041 T455310 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C22748 name=collection1 org.apache.solr.core.SolrCore@730af28d url=http://127.0.0.1:50360/x_/h/collection1 node=127.0.0.1:50360_x_%2Fh C22748_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:50360/x_/h, core=collection1, node_name=127.0.0.1:50360_x_%2Fh}
   [junit4]   2> 3004041 T455310 C22748 P50360 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50360/x_/h/collection1/
   [junit4]   2> 3004041 T455304 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3004042 T455310 C22748 P50360 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 3004042 T455310 C22748 P50360 oasc.SyncStrategy.syncToMe http://127.0.0.1:50360/x_/h/collection1/ has no replicas
   [junit4]   2> 3004042 T455310 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50360/x_/h/collection1/ shard1
   [junit4]   2> 3004043 T455310 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 3004044 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3004044 T455303 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> 3004044 T455312 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> 3004049 T455304 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3004051 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3004154 T455303 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> 3004154 T455312 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> 3004201 T455310 oasc.ZkController.register We are http://127.0.0.1:50360/x_/h/collection1/ and leader is http://127.0.0.1:50360/x_/h/collection1/
   [junit4]   2> 3004202 T455310 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50360/x_/h
   [junit4]   2> 3004202 T455310 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 3004202 T455310 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 3004202 T455310 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 3004204 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3004204 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3004204 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3004204 T455310 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3004205 T455304 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3004205 T455304 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50360/x_/h",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50360_x_%2Fh",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 3004215 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3004318 T455312 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> 3004318 T455303 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> 3005145 T455281 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 3005146 T455281 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 3005149 T455281 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:50417
   [junit4]   2> 3005150 T455281 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 3005150 T455281 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 3005150 T455281 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-003
   [junit4]   2> 3005151 T455281 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-003/'
   [junit4]   2> 3005180 T455281 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-003/solr.xml
   [junit4]   2> 3005231 T455281 oasc.CoreContainer.<init> New CoreContainer 1583061663
   [junit4]   2> 3005231 T455281 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-003/]
   [junit4]   2> 3005232 T455281 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 3005232 T455281 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 3005233 T455281 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 3005233 T455281 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 3005233 T455281 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 3005233 T455281 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 3005233 T455281 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 3005234 T455281 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 3005234 T455281 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 3005234 T455281 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 3005235 T455281 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 3005235 T455281 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 3005235 T455281 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:15150/solr
   [junit4]   2> 3005235 T455281 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 3005236 T455281 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3005238 T455323 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@50046d1e name:ZooKeeperConnection Watcher:127.0.0.1:15150 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3005241 T455281 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3005257 T455281 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3005259 T455325 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@60ae6bbc name:ZooKeeperConnection Watcher:127.0.0.1:15150/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3005259 T455281 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3005272 T455281 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 3006275 T455281 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50417_x_%2Fh
   [junit4]   2> 3006305 T455281 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50417_x_%2Fh
   [junit4]   2> 3006309 T455303 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 3006309 T455312 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 3006309 T455325 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 3006322 T455326 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 3006322 T455326 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 3006323 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3006323 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3006323 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3006323 T455326 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 3006324 T455304 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3006325 T455304 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50417/x_/h",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50417_x_%2Fh",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 3006325 T455304 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 3006325 T455304 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 3006333 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3006334 T455325 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> 3006334 T455312 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> 3006334 T455303 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> 3007324 T455326 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 3007325 T455326 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 3007325 T455326 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 3007326 T455326 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 3007326 T455326 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 3007326 T455326 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-003/collection1/'
   [junit4]   2> 3007328 T455326 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-003/collection1/lib/README' to classloader
   [junit4]   2> 3007328 T455326 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-003/collection1/lib/.svn/' to classloader
   [junit4]   2> 3007329 T455326 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-003/collection1/lib/classes/' to classloader
   [junit4]   2> 3007402 T455326 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_10
   [junit4]   2> 3007433 T455326 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 3007535 T455326 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 3007541 T455326 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 3007838 T455326 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 3007841 T455326 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 3007843 T455326 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 3007847 T455326 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 3007861 T455326 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 3007862 T455326 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 3007862 T455326 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-003/collection1/, dataDir=./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-001/jetty1/
   [junit4]   2> 3007862 T455326 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@61871708
   [junit4]   2> 3007863 T455326 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-001/jetty1
   [junit4]   2> 3007863 T455326 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-001/jetty1/index/
   [junit4]   2> 3007864 T455326 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-001/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 3007866 T455326 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-001/jetty1/index
   [junit4]   2> 3007867 T455326 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=17, maxMergeAtOnceExplicit=20, maxMergedSegmentMB=5.2294921875, floorSegmentMB=0.6162109375, forceMergeDeletesPctAllowed=26.593516805814566, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 3007868 T455326 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@4f55ad70 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7295da4),segFN=segments_1,generation=1}
   [junit4]   2> 3007868 T455326 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 3007871 T455326 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 3007871 T455326 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 3007871 T455326 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 3007872 T455326 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 3007872 T455326 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 3007872 T455326 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 3007873 T455326 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 3007873 T455326 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 3007873 T455326 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 3007874 T455326 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 3007874 T455326 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 3007874 T455326 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 3007874 T455326 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 3007875 T455326 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 3007875 T455326 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 3007876 T455326 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 3007894 T455326 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 3007899 T455326 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 3007899 T455326 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 3007900 T455326 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=44, maxMergeAtOnceExplicit=42, maxMergedSegmentMB=10.1904296875, floorSegmentMB=1.755859375, forceMergeDeletesPctAllowed=26.26056659028575, segmentsPerTier=38.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.767914023905204
   [junit4]   2> 3007900 T455326 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@4f55ad70 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7295da4),segFN=segments_1,generation=1}
   [junit4]   2> 3007901 T455326 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 3007901 T455326 oass.SolrIndexSearcher.<init> Opening Searcher@2803f8f8[collection1] main
   [junit4]   2> 3007901 T455326 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 3007902 T455326 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 3007902 T455326 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 3007903 T455326 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 3007903 T455326 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 3007903 T455326 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3007903 T455326 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 3007904 T455326 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3007904 T455326 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 3007904 T455326 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 3007907 T455327 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2803f8f8[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 3007909 T455326 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 3007909 T455330 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50417/x_/h collection:collection1 shard:shard1
   [junit4]   2> 3007909 T455281 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
   [junit4]   2> 3007910 T455330 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 3007910 T455281 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 3007927 T455330 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 3007938 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3007938 T455330 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 3007938 T455330 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C22749 name=collection1 org.apache.solr.core.SolrCore@7d56b881 url=http://127.0.0.1:50417/x_/h/collection1 node=127.0.0.1:50417_x_%2Fh C22749_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:50417/x_/h, core=collection1, node_name=127.0.0.1:50417_x_%2Fh}
   [junit4]   2> 3007939 T455330 C22749 P50417 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50417/x_/h/collection1/
   [junit4]   2> 3007939 T455304 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3007939 T455330 C22749 P50417 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 3007939 T455330 C22749 P50417 oasc.SyncStrategy.syncToMe http://127.0.0.1:50417/x_/h/collection1/ has no replicas
   [junit4]   2> 3007940 T455330 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50417/x_/h/collection1/ shard1
   [junit4]   2> 3007940 T455330 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3007941 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3007950 T455303 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> 3007951 T455325 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> 3007951 T455312 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> 3007962 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3007963 T455304 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3007965 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3008068 T455303 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> 3008068 T455312 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> 3008068 T455325 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> 3008115 T455330 oasc.ZkController.register We are http://127.0.0.1:50417/x_/h/collection1/ and leader is http://127.0.0.1:50417/x_/h/collection1/
   [junit4]   2> 3008116 T455330 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50417/x_/h
   [junit4]   2> 3008116 T455330 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 3008116 T455330 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 3008116 T455330 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 3008118 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3008118 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3008118 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3008118 T455330 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3008119 T455304 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3008119 T455304 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:50417/x_/h",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:50417_x_%2Fh",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 3008129 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3008232 T455303 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> 3008232 T455312 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> 3008232 T455325 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> 3008867 T455281 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 3008868 T455281 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 3008873 T455281 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:54345
   [junit4]   2> 3008874 T455281 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 3008874 T455281 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 3008874 T455281 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-004
   [junit4]   2> 3008874 T455281 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-004/'
   [junit4]   2> 3008903 T455281 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-004/solr.xml
   [junit4]   2> 3008953 T455281 oasc.CoreContainer.<init> New CoreContainer 1251860337
   [junit4]   2> 3008953 T455281 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-004/]
   [junit4]   2> 3008966 T455281 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 3008967 T455281 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 3008967 T455281 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 3008967 T455281 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 3008968 T455281 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 3008968 T455281 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 3008968 T455281 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 3008968 T455281 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 3008968 T455281 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 3008969 T455281 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 3008969 T455281 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 3008969 T455281 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 3008970 T455281 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:15150/solr
   [junit4]   2> 3008970 T455281 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 3008971 T455281 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3008973 T455341 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7e06943e name:ZooKeeperConnection Watcher:127.0.0.1:15150 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3008975 T455281 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3008990 T455281 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3008992 T455343 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@79598ef name:ZooKeeperConnection Watcher:127.0.0.1:15150/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3008992 T455281 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3009014 T455281 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 3010017 T455281 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54345_x_%2Fh
   [junit4]   2> 3010019 T455281 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54345_x_%2Fh
   [junit4]   2> 3010023 T455303 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 3010023 T455325 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 3010023 T455312 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 3010023 T455343 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 3010035 T455344 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 3010035 T455344 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 3010036 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3010036 T455344 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 3010036 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3010037 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3010037 T455304 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3010038 T455304 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:54345/x_/h",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:54345_x_%2Fh",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 3010038 T455304 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
   [junit4]   2> 3010038 T455304 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 3010041 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3010050 T455303 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> 3010050 T455343 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> 3010050 T455312 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> 3010050 T455325 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> 3011037 T455344 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 3011038 T455344 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 3011038 T455344 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 3011039 T455344 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 3011039 T455344 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 3011040 T455344 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-004/collection1/'
   [junit4]   2> 3011041 T455344 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-004/collection1/lib/README' to classloader
   [junit4]   2> 3011042 T455344 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-004/collection1/lib/classes/' to classloader
   [junit4]   2> 3011042 T455344 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1/solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-004/collection1/lib/.svn/' to classloader
   [junit4]   2> 3011105 T455344 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_10
   [junit4]   2> 3011149 T455344 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 3011251 T455344 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 3011260 T455344 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 3011623 T455344 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 3011626 T455344 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 3011627 T455344 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 3011631 T455344 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 3011646 T455344 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 3011646 T455344 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 3011647 T455344 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-004/collection1/, dataDir=./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-001/jetty2/
   [junit4]   2> 3011647 T455344 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@61871708
   [junit4]   2> 3011648 T455344 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-001/jetty2
   [junit4]   2> 3011648 T455344 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-001/jetty2/index/
   [junit4]   2> 3011648 T455344 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-001/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 3011651 T455344 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.RecoveryZkTest-EFDCB4F4D6D1BBF-001/tempDir-001/jetty2/index
   [junit4]   2> 3011651 T455344 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=17, maxMergeAtOnceExplicit=20, maxMergedSegmentMB=5.2294921875, floorSegmentMB=0.6162109375, forceMergeDeletesPctAllowed=26.593516805814566, segmentsPerTier=24.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 3011652 T455344 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@5a92c229 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@50992a80),segFN=segments_1,generation=1}
   [junit4]   2> 3011652 T455344 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 3011655 T455344 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 3011655 T455344 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 3011656 T455344 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 3011656 T455344 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 3011656 T455344 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 3011656 T455344 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 3011657 T455344 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 3011657 T455344 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 3011657 T455344 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 3011658 T455344 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 3011658 T455344 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 3011659 T455344 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 3011659 T455344 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 3011659 T455344 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 3011660 T455344 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 3011660 T455344 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 3011679 T455344 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 3011683 T455344 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 3011683 T455344 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 3011684 T455344 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=44, maxMergeAtOnceExplicit=42, maxMergedSegmentMB=10.1904296875, floorSegmentMB=1.755859375, forceMergeDeletesPctAllowed=26.26056659028575, segmentsPerTier=38.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.767914023905204
   [junit4]   2> 3011685 T455344 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@5a92c229 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@50992a80),segFN=segments_1,generation=1}
   [junit4]   2> 3011685 T455344 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 3011685 T455344 oass.SolrIndexSearcher.<init> Opening Searcher@14952904[collection1] main
   [junit4]   2> 3011686 T455344 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 3011686 T455344 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 3011687 T455344 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 3011687 T455344 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 3011687 T455344 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 3011687 T455344 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3011688 T455344 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 3011688 T455344 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3011688 T455344 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 3011689 T455344 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 3011691 T455345 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@14952904[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 3011693 T455344 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 3011694 T455348 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54345/x_/h collection:collection1 shard:shard1
   [junit4]   2> 3011694 T455281 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build/solr-core/test/J1
   [junit4]   2> 3011694 T455281 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 3011696 T455281 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3011696 T455348 oasc.ZkController.register We are http://127.0.0.1:54345/x_/h/collection1/ and leader is http://127.0.0.1:50417/x_/h/collection1/
   [junit4]   2> 3011697 T455348 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54345/x_/h
   [junit4]   2> 3011697 T455348 oasc.ZkController.checkRecovery Core needs to recover:collection1
   [junit4]   2> 3011701 T455348 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
   [junit4]   2> ASYNC  NEW_CORE C22750 name=collection1 org.apache.solr.core.SolrCore@23ab6d96 url=http://127.0.0.1:54345/x_/h/collection1 node=127.0.0.1:54345_x_%2Fh C22750_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:54345/x_/h, core=collection1, node_name=127.0.0.1:54345_x_%2Fh}
   [junit4]   2> 3011701 T455351 C22750 P54345 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
   [junit4]   2> 3011704 T455348 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3011704 T455351 C22750 P54345 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
   [junit4]   2> 3011704 T455351 C22750 P54345 oasc.RecoveryStrategy.doRecovery Publishing state of core collection1 as recovering, leader is http://127.0.0.1:50417/x_/h/collection1/ and I am http://127.0.0.1:54345/x_/h/collection1/
   [junit4]   2> 3011706 T455351 C22750 P54345 oasc.ZkController.publish publishing core=collection1 state=recovering collection=collection1
   [junit4]   2> 3011708 T455351 C22750 P54345 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 3011710 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> ASYNC  NEW_CORE C22751 name=collection1 org.apache.solr.core.SolrCore@730af28d url=http://127.0.0.1:50360/x_/h/collection1 node=127.0.0.1:50360_x_%2Fh C22751_STATE=coll:control_collection core:collection1 props:{state=active, base_url=http://127.0.0.1:50360/x_/h, core=collection1, node_name=127.0.0.1:50360_x_%2Fh, leader=true}
   [junit4]   2> 3011710 T455293 C22751 P50360 oasup.LogUpdateProcessor.finish [collection1] webapp=/x_/h path=/update params={version=2&wt=javabin&CONTROL=TRUE} {add=[2-0 (1472571095957635072)]} 0 6
   [junit4]   2> 3011710 T455351 C22750 P54345 oasc.RecoveryStrategy.sendPrepRecoveryCmd Sending prep recovery command to http://127.0.0.1:50417/x_/h; WaitForState: action=PREPRECOVERY&core=collection1&nodeName=127.0.0.1%3A54345_x_%252Fh&coreNodeName=core_node2&state=recovering&checkLive=true&onlyIfLeader=true&onlyIfLeaderActive=true
   [junit4]   2> 3011710 T455294 C22751 P50360 oasup.LogUpdateProcessor.finish [collection1] webapp=/x_/h path=/update params={version=2&wt=javabin&CONTROL=TRUE} {add=[1-0 (1472571095957635073)]} 0 6
   [junit4]   2> 3011711 T455304 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3011712 T455315 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true, onlyIfLeaderActive: true
   [junit4]   2> 3011712 T455304 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"recovering",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:54345/x_/h",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:54345_x_%2Fh",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 3011715 T455315 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3011720 T455315 oasha.CoreAdminHandler.handleWaitForStateAction Will wait a max of 183 seconds to see collection1 (shard1 of collection1) have state: recovering
   [junit4]   2> 3011721 T455315 oasha.CoreAdminHandler.handleWaitForStateAction In WaitForState(recovering): collection=collection1, shard=shard1, thisCore=collection1, leaderDoesNotNeedRecovery=false, isLeader? true, live=true, checkLive=true, currentState=down, localState=active, nodeName=127.0.0.1:54345_x_%2Fh, coreNodeName=core_node2, onlyIfActiveCheckResult=false, nodeProps: core_node2:{"state":"down","base_url":"http://127.0.0.1:54345/x_/h","core":"collection1","node_name":"127.0.0.1:54345_x_%2Fh"}
   [junit4]   2> ASYNC  NEW_CORE C22752 name=collection1 org.apache.solr.core.SolrCore@7d56b881 url=http://127.0.0.1:50417/x_/h/collection1 node=127.0.0.1:50417_x_%2Fh C22752_STATE=coll:collection1 core:collection1 props:{state=active, base_url=http://127.0.0.1:50417/x_/h, core=collection1, node_name=127.0.0.1:50417_x_%2Fh, leader=true}
   [junit4]   2> 3011721 T455316 C22752 P50417 oasup.LogUpdateProcessor.finish [collection1] webapp=/x_/h path=/update params={version=2&wt=javabin} {add=[2-0 (1472571095969169408)]} 0 9
   [junit4]   2> 3011721 T455303 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3011721 T455317 C22752 P50417 oasup.LogUpdateProcessor.finish [collection1] webapp=/x_/h path=/update params={version=2&wt=javabin} {add=[1-0 (1472571095970217984)]} 0 6
   [junit4]   2> 3011729 T455303 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> 3011729 T455343 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> 3011729 T4553

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

ngsFormat(name=Asserting), 46parent_f2_s=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 5grand3_s=PostingsFormat(name=FSTOrdPulsing41), 52parent_f1_s=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 39parent_f2_s=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 14parent_f2_s=PostingsFormat(name=FSTOrdPulsing41), 3grand0_s=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 12parent_f1_s=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 7grand4_s=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 38parent_f1_s=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 6parent_f2_s=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 49parent_f2_s=PostingsFormat(name=Asserting), 19parent_f2_s=MockVariableIntBlock(baseBlockSize=124), 6parent_f1_s=PostingsFormat(name=Asserting), 28parent_f2_s=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 2child0_s=PostingsFormat(name=FSTOrdPulsing41), 31parent_f1_s=PostingsFormat(name=FSTOrdPulsing41), 1parent_f1_s=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 17parent_f1_s=PostingsFormat(name=Asserting), 17parent_f2_s=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 48parent_f2_s=MockVariableIntBlock(baseBlockSize=124), 5grand2_s=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 1grand0_s=MockVariableIntBlock(baseBlockSize=124), 2grand1_s=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 5grand4_s=MockVariableIntBlock(baseBlockSize=124), 51parent_f1_s=PostingsFormat(name=Asserting), 31parent_f2_s=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 28parent_f1_s=PostingsFormat(name=Asserting), 7grand6_s=MockVariableIntBlock(baseBlockSize=124), 7grand1_s=PostingsFormat(name=FSTOrdPulsing41), 10parent_f1_s=MockVariableIntBlock(baseBlockSize=124), 7parent_f1_s=MockVariableIntBlock(baseBlockSize=124), 22parent_f2_s=MockVariableIntBlock(baseBlockSize=124), 2parent_f1_s=PostingsFormat(name=Asserting), 46parent_f1_s=PostingsFormat(name=FSTOrdPulsing41), 43parent_f1_s=MockVariableIntBlock(baseBlockSize=124), 25parent_f2_s=PostingsFormat(name=FSTOrdPulsing41), 16parent_f2_s=PostingsFormat(name=FSTOrdPulsing41), text_t=PostingsFormat(name=Asserting), 29parent_f2_s=PostingsFormat(name=Asserting), 6grand1_s=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 36parent_f2_s=PostingsFormat(name=FSTOrdPulsing41), 32parent_f2_s=PostingsFormat(name=FSTOrdPulsing41), 0parent_f1_s=PostingsFormat(name=FSTOrdPulsing41), 12parent_f2_s=PostingsFormat(name=Asserting), _version_=PostingsFormat(name=Asserting), 4parent_f1_s=PostingsFormat(name=FSTOrdPulsing41), 2child1_s=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 6grand4_s=PostingsFormat(name=FSTOrdPulsing41), 13parent_f1_s=PostingsFormat(name=FSTOrdPulsing41), 14parent_f1_s=MockVariableIntBlock(baseBlockSize=124), 45parent_f1_s=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 29parent_f1_s=MockVariableIntBlock(baseBlockSize=124), 27parent_f2_s=PostingsFormat(name=Asserting), 5parent_f1_s=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 4child0_s=PostingsFormat(name=FSTOrdPulsing41), 40parent_f2_s=MockVariableIntBlock(baseBlockSize=124), 8parent_f2_s=MockVariableIntBlock(baseBlockSize=124), 54parent_f2_s=PostingsFormat(name=FSTOrdPulsing41), 7grand0_s=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 22parent_f1_s=PostingsFormat(name=Asserting), 50parent_f1_s=MockVariableIntBlock(baseBlockSize=124), 23parent_f2_s=PostingsFormat(name=Asserting), 3grand1_s=PostingsFormat(name=FSTOrdPulsing41), 54parent_f1_s=MockVariableIntBlock(baseBlockSize=124), 41parent_f1_s=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 23parent_f1_s=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 35parent_f1_s=PostingsFormat(name=FSTOrdPulsing41), 24parent_f2_s=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 4grand1_s=MockVariableIntBlock(baseBlockSize=124), 33parent_f2_s=MockVariableIntBlock(baseBlockSize=124), id=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 18parent_f1_s=MockVariableIntBlock(baseBlockSize=124), 4child1_s=MockVariableIntBlock(baseBlockSize=124), 30parent_f2_s=PostingsFormat(name=Asserting), 33parent_f1_s=PostingsFormat(name=Asserting), 43parent_f2_s=PostingsFormat(name=FSTOrdPulsing41), 37parent_f2_s=MockVariableIntBlock(baseBlockSize=124), 7grand2_s=MockVariableIntBlock(baseBlockSize=124), 3child1_s=PostingsFormat(name=FSTOrdPulsing41), 55parent_f1_s=PostingsFormat(name=Asserting), 3parent_f1_s=MockVariableIntBlock(baseBlockSize=124), 53parent_f2_s=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 7parent_f2_s=PostingsFormat(name=Asserting), 44parent_f2_s=MockVariableIntBlock(baseBlockSize=124), 37parent_f1_s=PostingsFormat(name=Asserting), rnd_b=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 56parent_f2_s=PostingsFormat(name=Asserting), 25parent_f1_s=MockVariableIntBlock(baseBlockSize=124), 4child3_s=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 44parent_f1_s=PostingsFormat(name=Asserting), 26parent_f1_s=PostingsFormat(name=Asserting), 36parent_f1_s=MockVariableIntBlock(baseBlockSize=124), 55parent_f2_s=MockVariableIntBlock(baseBlockSize=124), 9parent_f1_s=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 4parent_f2_s=MockVariableIntBlock(baseBlockSize=124), 35parent_f2_s=Pulsing41(freqCutoff=17 minBlockSize=56 maxBlockSize=208), 21parent_f2_s=PostingsFormat(name=FSTOrdPulsing41), 3parent_f2_s=PostingsFormat(name=Asserting)}, docValues:{}, sim=DefaultSimilarity, locale=es_DO, timezone=America/Indiana/Knox
   [junit4]   2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_60 (64-bit)/cpus=16,threads=1,free=238880984,total=477102080
   [junit4]   2> NOTE: All tests run in this JVM: [AnalysisAfterCoreReloadTest, StatsComponentTest, TestSystemIdResolver, TestCoreContainer, TestAddFieldRealTimeGet, LeaderElectionIntegrationTest, TestIndexSearcher, DistributedQueryElevationComponentTest, TestCollationFieldDocValues, CSVRequestHandlerTest, HdfsUnloadDistributedZkTest, TestCursorMarkWithoutUniqueKey, TestElisionMultitermQuery, TestMiniSolrCloudCluster, AliasIntegrationTest, InfoHandlerTest, DirectSolrConnectionTest, FileUtilsTest, DistributedSuggestComponentTest, TestClassNameShortening, BJQParserTest, TestFastLRUCache, FieldAnalysisRequestHandlerTest, TestCollationKeyRangeQueries, AddSchemaFieldsUpdateProcessorFactoryTest, TestCSVLoader, TestDocumentBuilder, TestMultiCoreConfBootstrap, CollectionsAPIAsyncDistributedZkTest, HighlighterMaxOffsetTest, DocExpirationUpdateProcessorFactoryTest, TestGroupingSearch, HdfsDirectoryTest, TestFunctionQuery, DebugComponentTest, TestConfigSets, TestNonDefinedSimilarityFactory, TestXIncludeConfig, TestIBSimilarityFactory, TestLRUCache, TermVectorComponentDistributedTest, RequestHandlersTest, ShardRoutingCustomTest, TestManagedResourceStorage, HardAutoCommitTest, CurrencyFieldXmlFileTest, AssignTest, TestRecovery, SolrCoreTest, SearchHandlerTest, BasicDistributedZk2Test, SolrRequestParserTest, TestPHPSerializedResponseWriter, TestBinaryField, TestCSVResponseWriter, TestPerFieldSimilarity, AlternateDirectoryTest, TestImplicitCoreProperties, TestManagedStopFilterFactory, URLClassifyProcessorTest, TestValueSourceCache, SolrInfoMBeanTest, TestMergePolicyConfig, SolrPluginUtilsTest, TestCollationField, MultiThreadedOCPTest, BinaryUpdateRequestHandlerTest, TestFieldTypeCollectionResource, QueryParsingTest, PreAnalyzedFieldTest, CursorPagingTest, TestQueryTypes, CoreAdminRequestStatusTest, TestRTGBase, TestSchemaSimilarityResource, ShardSplitTest, TestDistribDocBasedVersion, TestSolrXmlPersistor, TermVectorComponentTest, TestCollapseQParserPlugin, LegacyHTMLStripCharFilterTest, TestDynamicFieldCollectionResource, TestWriterPerf, NumericFieldsTest, DirectUpdateHandlerOptimizeTest, DistributedTermsComponentTest, TestLeaderElectionZkExpiry, TestFreeTextSuggestions, DefaultValueUpdateProcessorTest, TestNonNRTOpen, TestUpdate, TestRealTimeGet, DeleteReplicaTest, SuggesterFSTTest, TestManagedSchemaFieldResource, CopyFieldTest, PolyFieldTest, ChaosMonkeySafeLeaderTest, CollectionsAPIDistributedZkTest, OpenCloseCoreStressTest, ShardRoutingTest, BasicZkTest, RecoveryZkTest, FullSolrCloudDistribCmdsTest]
   [junit4] Completed on J1 in 111.81s, 1 test, 1 error <<< FAILURES!

[...truncated 643 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:474: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:447: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/build.xml:45: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/extra-targets.xml:37: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/build.xml:189: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/solr/common-build.xml:496: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:1299: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.x/lucene/common-build.xml:923: There were test failures: 404 suites, 1654 tests, 1 error, 1 failure, 50 ignored (8 assumptions)

Total time: 238 minutes 37 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Sending artifact delta relative to Lucene-Solr-NightlyTests-4.x #567
Archived 3 artifacts
Archive block size is 32768
Received 0 blocks and 389990826 bytes
Compression is 0.0%
Took 1 min 6 sec
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message