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

[JENKINS] Lucene-Solr-NightlyTests-trunk - Build # 577 - Still Failing

Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-trunk/577/

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

Error Message:
No registered leader was found after waiting for 60000ms , collection: c8n_1x3_lf slice: shard1

Stack Trace:
org.apache.solr.common.SolrException: No registered leader was found after waiting for 60000ms , collection: c8n_1x3_lf slice: shard1
	at __randomizedtesting.SeedInfo.seed([7ABFE57023E18DF3:FB596B6854BEEDCF]:0)
	at org.apache.solr.common.cloud.ZkStateReader.getLeaderRetry(ZkStateReader.java:614)
	at org.apache.solr.cloud.HttpPartitionTest.testRf3WithLeaderFailover(HttpPartitionTest.java:349)
	at org.apache.solr.cloud.HttpPartitionTest.doTest(HttpPartitionTest.java:148)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:863)
	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.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)


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

Error Message:
No overseer designate as leader found after restart #1: 127.0.0.1:12551_vj_hxh

Stack Trace:
java.lang.AssertionError: No overseer designate as leader found after restart #1: 127.0.0.1:12551_vj_hxh
	at __randomizedtesting.SeedInfo.seed([7ABFE57023E18DF3:FB596B6854BEEDCF]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.RollingRestartTest.restartWithRolesTest(RollingRestartTest.java:100)
	at org.apache.solr.cloud.RollingRestartTest.doTest(RollingRestartTest.java:61)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:863)
	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.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 11580 lines...]
   [junit4] Suite: org.apache.solr.cloud.RollingRestartTest
   [junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/init-core-data-001
   [junit4]   2> 545338 T1257 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
   [junit4]   2> 545339 T1257 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /vj_hxh/
   [junit4]   2> 545343 T1257 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> 545344 T1257 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 545344 T1258 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 545444 T1257 oasc.ZkTestServer.run start zk server on port:13367
   [junit4]   2> 545445 T1257 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 545451 T1264 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@94fcb4b name:ZooKeeperConnection Watcher:127.0.0.1:13367 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 545451 T1257 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 545451 T1257 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 545472 T1257 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 545473 T1266 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6b510ae2 name:ZooKeeperConnection Watcher:127.0.0.1:13367/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 545473 T1257 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 545474 T1257 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 545484 T1257 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 545486 T1257 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 545489 T1257 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 545491 T1257 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 545491 T1257 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 545507 T1257 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 545507 T1257 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 545516 T1257 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 545517 T1257 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 545519 T1257 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 545519 T1257 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 545528 T1257 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 545528 T1257 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 545530 T1257 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 545531 T1257 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 545533 T1257 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 545533 T1257 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 545541 T1257 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 545541 T1257 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 545543 T1257 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 545544 T1257 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 545546 T1257 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 545547 T1257 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 545554 T1257 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 545554 T1257 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 545558 T1257 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 545568 T1268 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@34e8be96 name:ZooKeeperConnection Watcher:127.0.0.1:13367/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 545568 T1257 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 546426 T1257 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 546431 T1257 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 546433 T1257 oejs.AbstractConnector.doStart Started SslSocketConnector@127.0.0.1:13373
   [junit4]   2> 546435 T1257 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 546435 T1257 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 546436 T1257 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-002
   [junit4]   2> 546436 T1257 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-002/'
   [junit4]   2> 546465 T1257 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-002/solr.xml
   [junit4]   2> 546524 T1257 oasc.CoreContainer.<init> New CoreContainer 1840648088
   [junit4]   2> 546524 T1257 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-002/]
   [junit4]   2> 546525 T1257 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 546526 T1257 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 546526 T1257 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 546526 T1257 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 546526 T1257 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 546526 T1257 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 546527 T1257 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 546527 T1257 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 546527 T1257 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 546531 T1257 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 546531 T1257 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 546531 T1257 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 546531 T1257 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:13367/solr
   [junit4]   2> 546532 T1257 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 546532 T1257 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 546537 T1279 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7224e874 name:ZooKeeperConnection Watcher:127.0.0.1:13367 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 546538 T1257 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 546548 T1257 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 546550 T1281 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9ad2c48 name:ZooKeeperConnection Watcher:127.0.0.1:13367/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 546551 T1257 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 546558 T1257 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 546566 T1257 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 546569 T1257 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 546572 T1257 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 546583 T1257 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 546586 T1257 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 546594 T1257 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:13373_vj_hxh
   [junit4]   2> 546595 T1257 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:13373_vj_hxh
   [junit4]   2> 546597 T1257 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 546599 T1257 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 546602 T1257 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:13373_vj_hxh
   [junit4]   2> 546602 T1257 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 546603 T1257 oasc.Overseer.start Overseer (id=92038111513083908-127.0.0.1:13373_vj_hxh-n_0000000000) starting
   [junit4]   2> 546606 T1257 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 546624 T1283 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 546624 T1257 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 546626 T1257 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 546633 T1257 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 546635 T1282 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 546639 T1284 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 546640 T1284 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 546641 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 546641 T1284 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 546643 T1282 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:13373/vj_hxh",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:13373_vj_hxh",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 546643 T1282 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 546643 T1282 oasc.Overseer$ClusterStateUpdater.createCollection state version control_collection 1
   [junit4]   2> 546644 T1282 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 546652 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 546653 T1281 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> 547641 T1284 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 547642 T1284 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 547643 T1284 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 547643 T1284 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 547644 T1284 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 547644 T1284 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-002/collection1/'
   [junit4]   2> 547646 T1284 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-002/collection1/lib/classes/' to classloader
   [junit4]   2> 547647 T1284 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-002/collection1/lib/.svn/' to classloader
   [junit4]   2> 547648 T1284 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-002/collection1/lib/README' to classloader
   [junit4]   2> 547718 T1284 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
   [junit4]   2> 547766 T1284 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 547768 T1284 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 547778 T1284 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 548138 T1284 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 548154 T1284 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 548157 T1284 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 548171 T1284 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 548176 T1284 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 548180 T1284 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 548181 T1284 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 548182 T1284 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 548182 T1284 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 548183 T1284 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 548183 T1284 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 548184 T1284 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 548184 T1284 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 548184 T1284 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-002/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-001/control/data/
   [junit4]   2> 548184 T1284 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@46f8e15a
   [junit4]   2> 548187 T1284 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-001/control/data
   [junit4]   2> 548189 T1284 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-001/control/data/index/
   [junit4]   2> 548190 T1284 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-001/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 548192 T1284 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-001/control/data/index
   [junit4]   2> 548192 T1284 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@5c57f86c
   [junit4]   2> 548211 T1284 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-001/control/data/index,segFN=segments_1,generation=1}
   [junit4]   2> 548212 T1284 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 548217 T1284 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 548217 T1284 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 548218 T1284 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 548218 T1284 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 548218 T1284 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 548218 T1284 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 548219 T1284 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 548219 T1284 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 548219 T1284 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 548220 T1284 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 548220 T1284 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 548221 T1284 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 548221 T1284 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 548221 T1284 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 548222 T1284 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 548222 T1284 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 548223 T1284 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 548247 T1284 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 548251 T1284 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 548251 T1284 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 548252 T1284 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=5, maxMergeAtOnceExplicit=8, maxMergedSegmentMB=66.3486328125, floorSegmentMB=0.568359375, forceMergeDeletesPctAllowed=16.08597997641977, segmentsPerTier=33.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 548254 T1284 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-001/control/data/index,segFN=segments_1,generation=1}
   [junit4]   2> 548254 T1284 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 548255 T1284 oass.SolrIndexSearcher.<init> Opening Searcher@1e11514e[collection1] main
   [junit4]   2> 548255 T1284 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 548256 T1284 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 548256 T1284 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 548257 T1284 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 548257 T1284 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 548257 T1284 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 548258 T1284 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 548258 T1284 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 548258 T1284 oascc.SolrZkClient.makePath makePath: /configs/conf1/_rest_managed.json
   [junit4]   2> 548261 T1284 oasr.ManagedResourceStorage$ZooKeeperStorageIO$1.close Wrote 38 bytes to new znode /configs/conf1/_rest_managed.json
   [junit4]   2> 548261 T1284 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 548262 T1284 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 548265 T1285 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1e11514e[collection1] main{UninvertingDirectoryReader()}
   [junit4]   2> 548267 T1284 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 548268 T1288 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:13373/vj_hxh collection:control_collection shard:shard1
   [junit4]   2> 548268 T1257 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1
   [junit4]   2> 548269 T1257 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 548269 T1288 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 548274 T1257 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 548283 T1290 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3786b8cc name:ZooKeeperConnection Watcher:127.0.0.1:13367/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 548283 T1257 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 548290 T1257 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 548291 T1288 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 548301 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 548302 T1288 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 548302 T1288 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C252 name=collection1 org.apache.solr.core.SolrCore@4d1a4d5c url=https://127.0.0.1:13373/vj_hxh/collection1 node=127.0.0.1:13373_vj_hxh C252_STATE=coll:control_collection core:collection1 props:{state=down, base_url=https://127.0.0.1:13373/vj_hxh, core=collection1, node_name=127.0.0.1:13373_vj_hxh}
   [junit4]   2> 548302 T1288 C252 P13373 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:13373/vj_hxh/collection1/
   [junit4]   2> 548303 T1257 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 548303 T1288 C252 P13373 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 548303 T1288 C252 P13373 oasc.SyncStrategy.syncToMe https://127.0.0.1:13373/vj_hxh/collection1/ has no replicas
   [junit4]   2> 548303 T1288 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:13373/vj_hxh/collection1/ shard1
   [junit4]   2> 548303 T1288 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 548316 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 548317 T1281 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> 548317 T1290 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> 548333 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 548437 T1281 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> 548437 T1290 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> 548481 T1288 oasc.ZkController.register We are https://127.0.0.1:13373/vj_hxh/collection1/ and leader is https://127.0.0.1:13373/vj_hxh/collection1/
   [junit4]   2> 548482 T1288 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:13373/vj_hxh
   [junit4]   2> 548482 T1288 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 548482 T1288 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 548482 T1288 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 548484 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 548484 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 548484 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 548487 T1282 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:13373/vj_hxh",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:13373_vj_hxh",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 548490 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 548592 T1281 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> 548592 T1290 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> 549787 T1257 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 549788 T1257 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 549793 T1257 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 549795 T1257 oejs.AbstractConnector.doStart Started SslSocketConnector@127.0.0.1:13383
   [junit4]   2> 549797 T1257 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 549797 T1257 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 549797 T1257 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-003
   [junit4]   2> 549797 T1257 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-003/'
   [junit4]   2> 549827 T1257 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-003/solr.xml
   [junit4]   2> 549877 T1257 oasc.CoreContainer.<init> New CoreContainer 805423953
   [junit4]   2> 549877 T1257 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-003/]
   [junit4]   2> 549878 T1257 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 549879 T1257 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 549879 T1257 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 549879 T1257 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 549879 T1257 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 549879 T1257 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 549880 T1257 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 549880 T1257 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 549880 T1257 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 549884 T1257 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 549884 T1257 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 549884 T1257 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 549884 T1257 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:13367/solr
   [junit4]   2> 549885 T1257 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 549885 T1257 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 549887 T1301 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3154bfa8 name:ZooKeeperConnection Watcher:127.0.0.1:13367 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 549888 T1257 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 549890 T1257 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 549899 T1303 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4f78b27e name:ZooKeeperConnection Watcher:127.0.0.1:13367/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 549899 T1257 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 549916 T1257 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 550920 T1257 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:13383_vj_hxh
   [junit4]   2> 550922 T1257 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:13383_vj_hxh
   [junit4]   2> 550938 T1304 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 550938 T1304 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 550940 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 550940 T1304 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 550940 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 550940 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 550942 T1282 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:13383/vj_hxh",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:13383_vj_hxh",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 550943 T1282 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 550943 T1282 oasc.Overseer$ClusterStateUpdater.createCollection state version collection1 1
   [junit4]   2> 550943 T1282 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 550946 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 550955 T1303 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> 550955 T1290 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> 550955 T1281 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> 551940 T1304 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 551941 T1304 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 551942 T1304 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 551942 T1304 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 551943 T1304 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 551943 T1304 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-003/collection1/'
   [junit4]   2> 551945 T1304 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-003/collection1/lib/README' to classloader
   [junit4]   2> 551946 T1304 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-003/collection1/lib/classes/' to classloader
   [junit4]   2> 551947 T1304 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-003/collection1/lib/.svn/' to classloader
   [junit4]   2> 552011 T1304 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
   [junit4]   2> 552056 T1304 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 552057 T1304 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 552067 T1304 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 552428 T1304 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 552443 T1304 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 552445 T1304 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 552466 T1304 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 552483 T1304 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 552494 T1304 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 552496 T1304 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 552497 T1304 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 552497 T1304 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 552498 T1304 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 552499 T1304 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 552499 T1304 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 552499 T1304 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 552500 T1304 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-003/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-001/jetty1/
   [junit4]   2> 552500 T1304 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@46f8e15a
   [junit4]   2> 552502 T1304 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-001/jetty1
   [junit4]   2> 552503 T1304 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-001/jetty1/index/
   [junit4]   2> 552504 T1304 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-001/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 552505 T1304 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-001/jetty1/index
   [junit4]   2> 552505 T1304 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@367117a4
   [junit4]   2> 552551 T1304 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-001/jetty1/index,segFN=segments_1,generation=1}
   [junit4]   2> 552551 T1304 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 552559 T1304 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 552559 T1304 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 552559 T1304 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 552560 T1304 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 552560 T1304 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 552560 T1304 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 552561 T1304 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 552561 T1304 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 552561 T1304 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 552562 T1304 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 552563 T1304 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 552563 T1304 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 552563 T1304 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 552564 T1304 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 552564 T1304 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 552565 T1304 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 552566 T1304 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 552593 T1304 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 552597 T1304 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 552597 T1304 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 552598 T1304 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=5, maxMergeAtOnceExplicit=8, maxMergedSegmentMB=66.3486328125, floorSegmentMB=0.568359375, forceMergeDeletesPctAllowed=16.08597997641977, segmentsPerTier=33.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 552601 T1304 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-001/jetty1/index,segFN=segments_1,generation=1}
   [junit4]   2> 552601 T1304 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 552601 T1304 oass.SolrIndexSearcher.<init> Opening Searcher@179682b2[collection1] main
   [junit4]   2> 552602 T1304 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 552603 T1304 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 552603 T1304 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 552603 T1304 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 552604 T1304 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 552604 T1304 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 552605 T1304 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json
   [junit4]   2> 552605 T1304 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 552605 T1304 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed
   [junit4]   2> 552605 T1304 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 552610 T1305 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@179682b2[collection1] main{UninvertingDirectoryReader()}
   [junit4]   2> 552614 T1304 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 552615 T1308 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:13383/vj_hxh collection:collection1 shard:shard1
   [junit4]   2> 552615 T1257 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1
   [junit4]   2> 552615 T1257 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 552615 T1308 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 552716 T1308 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 552741 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 552741 T1308 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 552741 T1308 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C253 name=collection1 org.apache.solr.core.SolrCore@497a890b url=https://127.0.0.1:13383/vj_hxh/collection1 node=127.0.0.1:13383_vj_hxh C253_STATE=coll:collection1 core:collection1 props:{state=down, base_url=https://127.0.0.1:13383/vj_hxh, core=collection1, node_name=127.0.0.1:13383_vj_hxh}
   [junit4]   2> 552742 T1308 C253 P13383 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:13383/vj_hxh/collection1/
   [junit4]   2> 552742 T1308 C253 P13383 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 552742 T1308 C253 P13383 oasc.SyncStrategy.syncToMe https://127.0.0.1:13383/vj_hxh/collection1/ has no replicas
   [junit4]   2> 552742 T1308 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:13383/vj_hxh/collection1/ shard1
   [junit4]   2> 552742 T1308 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 552776 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 552782 T1281 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> 552782 T1290 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> 552782 T1303 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> 552797 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 552899 T1290 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> 552899 T1303 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> 552899 T1281 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> 552944 T1308 oasc.ZkController.register We are https://127.0.0.1:13383/vj_hxh/collection1/ and leader is https://127.0.0.1:13383/vj_hxh/collection1/
   [junit4]   2> 552945 T1308 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:13383/vj_hxh
   [junit4]   2> 552945 T1308 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 552945 T1308 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 552945 T1308 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 552961 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 552962 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 552962 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 552964 T1282 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:13383/vj_hxh",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:13383_vj_hxh",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 552978 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 553083 T1290 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> 553083 T1281 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> 553083 T1303 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> 553759 T1257 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 553760 T1257 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 553765 T1257 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 553767 T1257 oejs.AbstractConnector.doStart Started SslSocketConnector@127.0.0.1:13392
   [junit4]   2> 553769 T1257 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 553769 T1257 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 553769 T1257 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-004
   [junit4]   2> 553770 T1257 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-004/'
   [junit4]   2> 553799 T1257 oasc.ConfigSolr.fromFile Loading container configuration from /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-004/solr.xml
   [junit4]   2> 553848 T1257 oasc.CoreContainer.<init> New CoreContainer 412780096
   [junit4]   2> 553849 T1257 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-004/]
   [junit4]   2> 553850 T1257 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 553850 T1257 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 553850 T1257 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 553850 T1257 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 553851 T1257 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 553851 T1257 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 553851 T1257 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 553851 T1257 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 553851 T1257 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 553855 T1257 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 553855 T1257 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 553855 T1257 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 553856 T1257 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:13367/solr
   [junit4]   2> 553856 T1257 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 553857 T1257 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 553859 T1319 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@33cb923f name:ZooKeeperConnection Watcher:127.0.0.1:13367 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 553859 T1257 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 553862 T1257 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 553871 T1321 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18498ff3 name:ZooKeeperConnection Watcher:127.0.0.1:13367/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 553871 T1257 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 553888 T1257 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 554892 T1257 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:13392_vj_hxh
   [junit4]   2> 554894 T1257 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:13392_vj_hxh
   [junit4]   2> 554905 T1322 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 554905 T1322 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 554907 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 554907 T1322 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 554907 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 554907 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 554909 T1282 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:13392/vj_hxh",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:13392_vj_hxh",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 554910 T1282 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 554910 T1282 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 554912 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 554922 T1290 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> 554922 T1303 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> 554922 T1281 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> 554922 T1321 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> 555907 T1322 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 555908 T1322 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 555909 T1322 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 555909 T1322 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 555910 T1322 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 555910 T1322 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-004/collection1/'
   [junit4]   2> 555912 T1322 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-004/collection1/lib/classes/' to classloader
   [junit4]   2> 555913 T1322 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-004/collection1/lib/README' to classloader
   [junit4]   2> 555914 T1322 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-004/collection1/lib/.svn/' to classloader
   [junit4]   2> 555983 T1322 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
   [junit4]   2> 556030 T1322 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 556032 T1322 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 556042 T1322 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 556414 T1322 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 556431 T1322 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 556434 T1322 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 556447 T1322 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 556452 T1322 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 556457 T1322 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 556457 T1322 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 556458 T1322 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 556459 T1322 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 556459 T1322 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 556460 T1322 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 556460 T1322 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 556460 T1322 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 556460 T1322 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../../usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-004/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-001/jetty2/
   [junit4]   2> 556461 T1322 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@46f8e15a
   [junit4]   2> 556463 T1322 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-001/jetty2
   [junit4]   2> 556464 T1322 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-001/jetty2/index/
   [junit4]   2> 556466 T1322 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-001/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 556467 T1322 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-001/jetty2/index
   [junit4]   2> 556467 T1322 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@3bb1a3a6
   [junit4]   2> 556483 T1322 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-001/jetty2/index,segFN=segments_1,generation=1}
   [junit4]   2> 556483 T1322 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 556490 T1322 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 556491 T1322 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 556491 T1322 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 556491 T1322 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 556492 T1322 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 556492 T1322 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 556492 T1322 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 556493 T1322 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 556493 T1322 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 556494 T1322 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 556494 T1322 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 556494 T1322 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 556495 T1322 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 556495 T1322 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 556496 T1322 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 556497 T1322 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 556498 T1322 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 556524 T1322 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 556528 T1322 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 556528 T1322 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 556529 T1322 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=5, maxMergeAtOnceExplicit=8, maxMergedSegmentMB=66.3486328125, floorSegmentMB=0.568359375, forceMergeDeletesPctAllowed=16.08597997641977, segmentsPerTier=33.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 556532 T1322 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/temp/solr.cloud.RollingRestartTest-7ABFE57023E18DF3-001/tempDir-001/jetty2/index,segFN=segments_1,generation=1}
   [junit4]   2> 556532 T1322 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 556532 T1322 oass.SolrIndexSearcher.<init> Opening Searcher@7ee5ed2e[collection1] main
   [junit4]   2> 556532 T1322 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 556533 T1322 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 556534 T1322 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 556534 T1322 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 556534 T1322 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 556535 T1322 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 556535 T1322 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json
   [junit4]   2> 556536 T1322 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 556536 T1322 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed
   [junit4]   2> 556536 T1322 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 556540 T1323 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7ee5ed2e[collection1] main{UninvertingDirectoryReader()}
   [junit4]   2> 556544 T1322 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 556545 T1326 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:13392/vj_hxh collection:collection1 shard:shard2
   [junit4]   2> 556545 T1257 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1
   [junit4]   2> 556545 T1257 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 556546 T1326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 556560 T1326 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 556564 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 556564 T1326 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 556564 T1326 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C254 name=collection1 org.apache.solr.core.SolrCore@3246246f url=https://127.0.0.1:13392/vj_hxh/collection1 node=127.0.0.1:13392_vj_hxh C254_STATE=coll:collection1 core:collection1 props:{state=down, base_url=https://127.0.0.1:13392/vj_hxh, core=collection1, node_name=127.0.0.1:13392_vj_hxh}
   [junit4]   2> 556565 T1326 C254 P13392 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:13392/vj_hxh/collection1/
   [junit4]   2> 556565 T1326 C254 P13392 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 556565 T1326 C254 P13392 oasc.SyncStrategy.syncToMe https://127.0.0.1:13392/vj_hxh/collection1/ has no replicas
   [junit4]   2> 556565 T1326 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:13392/vj_hxh/collection1/ shard2
   [junit4]   2> 556566 T1326 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 556578 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 556590 T1281 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> 556590 T1303 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> 556590 T1321 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> 556590 T1290 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> 556604 T1281 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 556707 T1303 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> 556707 T1281 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> 556707 T1290 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> 556707 T1321 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> 556751 T1326 oasc.ZkController.register We are https://127.0.0.1:13392/vj_hxh/collection1/ and leader is https://127.0.0.1:13392/vj_hxh/collection1/
   [junit4]   2> 556752 T1326 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:13392/vj_hxh
   [junit4]   2> 556752 T1326 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 556752 T1326 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 556752 T1326 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 556754 T1281 oasc.Distributed

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

teMethod(HttpSolrServer.java:452)
   [junit4]   2> 		... 6 more
   [junit4]   2> 	
   [junit4]   2> 3871305 T33719 oasc.Overseer$ClusterStateUpdater.run Overseer Loop exiting : 127.0.0.1:17607_
   [junit4]   2> 3871307 T33396 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
   [junit4]   2> 3871360 T33396 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 17614
   [junit4]   2> 3871361 T33396 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
   [junit4]   2> 3871362 T33396 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:17574 17574
   [junit4]   2> 3871464 T33397 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:17574 17574
   [junit4]   2> 3871465 T33396 oasc.SocketProxy.close WARN Closing 0 connections to: http://127.0.0.1:17607/
   [junit4]   2> 3871465 T33396 oasc.SocketProxy.close WARN Closing 0 connections to: http://127.0.0.1:17614/
   [junit4]   2> 3871466 T33396 oasc.SocketProxy.close WARN Closing 0 connections to: http://127.0.0.1:17594/
   [junit4]   2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=HttpPartitionTest -Dtests.method=testDistribSearch -Dtests.seed=7ABFE57023E18DF3 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/hudson/lucene-data/enwiki.random.lines.txt -Dtests.locale=uk_UA -Dtests.timezone=America/Argentina/Salta -Dtests.file.encoding=US-ASCII
   [junit4] ERROR    687s J1 | HttpPartitionTest.testDistribSearch <<<
   [junit4]    > Throwable #1: org.apache.solr.common.SolrException: No registered leader was found after waiting for 60000ms , collection: c8n_1x3_lf slice: shard1
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([7ABFE57023E18DF3:FB596B6854BEEDCF]:0)
   [junit4]    > 	at org.apache.solr.common.cloud.ZkStateReader.getLeaderRetry(ZkStateReader.java:614)
   [junit4]    > 	at org.apache.solr.cloud.HttpPartitionTest.testRf3WithLeaderFailover(HttpPartitionTest.java:349)
   [junit4]    > 	at org.apache.solr.cloud.HttpPartitionTest.doTest(HttpPartitionTest.java:148)
   [junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:863)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 3871486 T33396 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-trunk/solr/build/solr-core/test/J1/./temp/solr.cloud.HttpPartitionTest-7ABFE57023E18DF3-001
   [junit4]   2> 686684 T33395 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
   [junit4]   2> 3872805 T33722 oasc.Overseer$ClusterStateUpdater.checkIfIamStillLeader ERROR could not read the data org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/leader
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getData(ZooKeeper.java:1155)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:277)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$7.execute(SolrZkClient.java:274)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getData(SolrZkClient.java:274)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.checkIfIamStillLeader(Overseer.java:342)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater.access$300(Overseer.java:86)
   [junit4]   2> 	at org.apache.solr.cloud.Overseer$ClusterStateUpdater$1.run(Overseer.java:294)
   [junit4]   2> 
   [junit4]   2> 3872806 T33441 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> NOTE: test params are: codec=Lucene45, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=uk_UA, timezone=America/Argentina/Salta
   [junit4]   2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_60 (64-bit)/cpus=16,threads=1,free=94024976,total=517472256
   [junit4]   2> NOTE: All tests run in this JVM: [AbstractAnalyticsFacetTest, TestUpdate, TestComplexPhraseQParserPlugin, StressHdfsTest, TermVectorComponentDistributedTest, TestShortCircuitedRequests, CacheHeaderTest, TestPhraseSuggestions, ShardSplitTest, SSLMigrationTest, TestRandomMergePolicy, TestNonNRTOpen, AnalysisAfterCoreReloadTest, TestRestManager, MultiTermTest, TestSolrXMLSerializer, CachingDirectoryFactoryTest, TestIBSimilarityFactory, MergeStrategyTest, TestElisionMultitermQuery, LukeRequestHandlerTest, TestPostingsSolrHighlighter, TestManagedSchemaFieldResource, RollingRestartTest, HdfsChaosMonkeySafeLeaderTest, TestCSVResponseWriter, TestExtendedDismaxParser, TestLRUCache, TestQueryUtils, TestCollationField, DocValuesTest, TestGroupingSearch, SolrRequestParserTest, AnalyticsMergeStrategyTest, DirectUpdateHandlerOptimizeTest, DistanceFunctionTest, SimplePostToolTest, AtomicUpdatesTest, TestNRTOpen, SearchHandlerTest, DistributedQueryElevationComponentTest, SuggesterFSTTest, TestCursorMarkWithoutUniqueKey, TestReversedWildcardFilterFactory, TestRealTimeGet, IndexSchemaRuntimeFieldTest, TestDistribDocBasedVersion, CSVRequestHandlerTest, AddBlockUpdateTest, TestJoin, ShardRoutingCustomTest, TestInfoStreamLogging, UpdateRequestProcessorFactoryTest, SolrIndexConfigTest, SliceStateTest, SystemInfoHandlerTest, ResponseHeaderTest, OpenCloseCoreStressTest, TestShardHandlerFactory, LeaderElectionIntegrationTest, BasicDistributedZk2Test, TestSolrQueryParserDefaultOperatorResource, TestZkChroot, ExternalCollectionsTest, TestSchemaNameResource, AutoCommitTest, TestCSVLoader, SpatialFilterTest, HardAutoCommitTest, TestClassNameShortening, CoreContainerCoreInitFailuresTest, TestRecovery, BJQParserTest, BinaryUpdateRequestHandlerTest, TestQueryTypes, TestSolrQueryParser, QueryParsingTest, FieldAnalysisRequestHandlerTest, TestUniqueKeyFieldResource, BasicZkTest, AlternateDirectoryTest, ResourceLoaderTest, ConvertedLegacyTest, TestSystemIdResolver, TestBM25SimilarityFactory, DistributedSuggestComponentTest, TestSolrXmlPersistor, TestMaxScoreQueryParser, NumericFieldsTest, TestIndexingPerformance, TestValueSourceCache, TestPseudoReturnFields, ChaosMonkeySafeLeaderTest, OutputWriterTest, SolrPluginUtilsTest, TestQuerySenderNoQuery, TestWriterPerf, TestJmxMonitoredMap, TestRandomFaceting, LeaderElectionTest, ZkSolrClientTest, TestDistributedSearch, TestDistributedGrouping, TestFaceting, DistributedSpellCheckComponentTest, ZkControllerTest, TestStressReorder, TestMultiCoreConfBootstrap, TestStressVersions, DistributedTermsComponentTest, TestRangeQuery, TestCoreContainer, SolrCoreTest, StatsComponentTest, SpellCheckComponentTest, SolrCmdDistributorTest, QueryElevationComponentTest, TestFiltering, TestLazyCores, SoftAutoCommitTest, SpellCheckCollatorTest, SuggesterTSTTest, SuggesterTest, SuggesterWFSTTest, WordBreakSolrSpellCheckerTest, SolrCoreCheckLockOnStartupTest, TestAtomicUpdateErrorCases, DefaultValueUpdateProcessorTest, TestRemoteStreaming, DebugComponentTest, PrimitiveFieldTypeTest, FileBasedSpellCheckerTest, XmlUpdateRequestHandlerTest, PathHierarchyTokenizerFactoryTest, TestArbitraryIndexDir, RegexBoostProcessorTest, TestJmxIntegration, TestAnalyzedSuggestions, TestPartialUpdateDeduplication, TestComponentsName, HighlighterConfigTest, TestQuerySenderListener, TestMergePolicyConfig, TestBinaryField, MinimalSchemaTest, ExternalFileFieldSortTest, DirectSolrConnectionTest, TestLuceneMatchVersion, TestCharFilters, SynonymTokenizerTest, EchoParamsTest, TestPerFieldSimilarity, TestLMJelinekMercerSimilarityFactory, URLClassifyProcessorTest, TestFastLRUCache, PreAnalyzedFieldTest, RAMDirectoryFactoryTest, FileUtilsTest, TestDistributedMissingSort, ExpressionTest, QueryFacetTest, AliasIntegrationTest, CollectionsAPIAsyncDistributedZkTest, DeleteInactiveReplicaTest, DistribCursorPagingTest, HttpPartitionTest]
   [junit4] Completed on J1 in 688.22s, 1 test, 1 error <<< FAILURES!

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

Total time: 194 minutes 12 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Sending artifact delta relative to Lucene-Solr-NightlyTests-trunk #564
Archived 3 artifacts
Archive block size is 32768
Received 0 blocks and 609342978 bytes
Compression is 0.0%
Took 1 min 50 sec
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure