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

[JENKINS] Lucene-Solr-4.x-Linux (32bit/jdk1.8.0_20-ea-b15) - Build # 10611 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/10611/
Java: 32bit/jdk1.8.0_20-ea-b15 -server -XX:+UseSerialGC

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

Error Message:
No live SolrServers available to handle this request:[http://127.0.0.1:57410/_, http://127.0.0.1:53613/_, http://127.0.0.1:36639/_, http://127.0.0.1:56326/_, http://127.0.0.1:56999/_]

Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:57410/_, http://127.0.0.1:53613/_, http://127.0.0.1:36639/_, http://127.0.0.1:56326/_, http://127.0.0.1:56999/_]
	at __randomizedtesting.SeedInfo.seed([2A25DBBEAD08DE72:ABC355A6DA57BE4E]:0)
	at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:319)
	at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:659)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1513)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.createCollection(AbstractFullDistribZkTestBase.java:1539)
	at org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.testIndexingBatchPerRequestWithHttpSolrServer(FullSolrCloudDistribCmdsTest.java:355)
	at org.apache.solr.cloud.FullSolrCloudDistribCmdsTest.doTest(FullSolrCloudDistribCmdsTest.java:145)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:865)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:483)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
	at java.lang.Thread.run(Thread.java:745)
Caused by: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: org.apache.solr.common.SolrException
	at org.apache.solr.handler.admin.CollectionsHandler.handleResponse(CollectionsHandler.java:364)
	at org.apache.solr.handler.admin.CollectionsHandler.handleResponse(CollectionsHandler.java:320)
	at org.apache.solr.handler.admin.CollectionsHandler.handleCreateAction(CollectionsHandler.java:485)
	at org.apache.solr.handler.admin.CollectionsHandler.handleRequestBody(CollectionsHandler.java:148)
	at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:135)
	at org.apache.solr.servlet.SolrDispatchFilter.handleAdminRequest(SolrDispatchFilter.java:729)
	at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:267)
	at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:207)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1419)
	at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:136)
	at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1419)
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:455)
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:229)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:137)
	at org.eclipse.jetty.server.handler.GzipHandler.handle(GzipHandler.java:301)
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1077)
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:384)
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:193)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1009)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:135)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:116)
	at org.eclipse.jetty.server.Server.handle(Server.java:368)
	at org.eclipse.jetty.server.AbstractHttpConnection.handleRequest(AbstractHttpConnection.java:489)
	at org.eclipse.jetty.server.AbstractHttpConnection.headerComplete(AbstractHttpConnection.java:942)
	at org.eclipse.jetty.server.AbstractHttpConnection$RequestHandler.headerComplete(AbstractHttpConnection.java:1004)
	at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:640)
	at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:235)
	at org.eclipse.jetty.server.AsyncHttpConnection.handle(AsyncHttpConnection.java:82)
	at org.eclipse.jetty.io.nio.SelectChannelEndPoint.handle(SelectChannelEndPoint.java:628)
	at org.eclipse.jetty.io.nio.SelectChannelEndPoint$1.run(SelectChannelEndPoint.java:52)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
	at java.lang.Thread.run(Thread.java:745)

	at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:554)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:210)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:206)
	at org.apache.solr.client.solrj.impl.LBHttpSolrServer.doRequest(LBHttpSolrServer.java:340)
	at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:301)
	... 47 more




Build Log:
[...truncated 11691 lines...]
   [junit4] Suite: org.apache.solr.cloud.FullSolrCloudDistribCmdsTest
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/init-core-data-001
   [junit4]   2> 975028 T5461 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /_/
   [junit4]   2> 975031 T5461 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> 975032 T5461 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 975033 T5462 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 975132 T5461 oasc.ZkTestServer.run start zk server on port:49023
   [junit4]   2> 975133 T5461 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 975594 T5468 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@705886 name:ZooKeeperConnection Watcher:127.0.0.1:49023 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 975594 T5461 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 975594 T5461 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 975598 T5461 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 975599 T5470 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1bea27e name:ZooKeeperConnection Watcher:127.0.0.1:49023/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 975599 T5461 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 975599 T5461 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 975601 T5461 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 975602 T5461 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 975603 T5461 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 975605 T5461 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 975605 T5461 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 975607 T5461 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
   [junit4]   2> 975608 T5461 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 975610 T5461 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 975610 T5461 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 975612 T5461 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 975612 T5461 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 975615 T5461 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 975615 T5461 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 975617 T5461 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 975617 T5461 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 975619 T5461 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 975620 T5461 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 975621 T5461 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 975622 T5461 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 975623 T5461 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 975624 T5461 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 975626 T5461 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 975626 T5461 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 975629 T5461 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 975630 T5461 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 975881 T5461 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 975887 T5461 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:36639
   [junit4]   2> 975888 T5461 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 975888 T5461 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 975889 T5461 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-002
   [junit4]   2> 975889 T5461 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-002/'
   [junit4]   2> 975900 T5461 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-002/solr.xml
   [junit4]   2> 975907 T5461 oasc.CoreContainer.<init> New CoreContainer 32422076
   [junit4]   2> 975907 T5461 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-002/]
   [junit4]   2> 975908 T5461 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 975908 T5461 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 975908 T5461 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 975909 T5461 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 975909 T5461 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 975909 T5461 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 975909 T5461 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 975910 T5461 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 975910 T5461 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 975911 T5461 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 975911 T5461 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 975911 T5461 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 975912 T5461 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49023/solr
   [junit4]   2> 975912 T5461 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 975913 T5461 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 975914 T5481 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@155717a name:ZooKeeperConnection Watcher:127.0.0.1:49023 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 975915 T5461 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 975917 T5461 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 975917 T5483 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8c3e70 name:ZooKeeperConnection Watcher:127.0.0.1:49023/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 975918 T5461 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 975919 T5461 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 975923 T5461 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 975925 T5461 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 975927 T5461 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 975930 T5461 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 975932 T5461 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 975934 T5461 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36639__
   [junit4]   2> 975935 T5461 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36639__
   [junit4]   2> 975937 T5461 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 975938 T5461 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 975940 T5461 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:36639__
   [junit4]   2> 975940 T5461 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 975942 T5461 oasc.Overseer.start Overseer (id=92050395771109379-127.0.0.1:36639__-n_0000000000) starting
   [junit4]   2> 975948 T5461 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 975952 T5485 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 975952 T5461 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 975954 T5461 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 975955 T5461 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 975956 T5484 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 975958 T5486 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 975958 T5486 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 975958 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 975958 T5486 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 975959 T5484 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 975960 T5484 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:36639/_",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:36639__",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 975960 T5484 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 975960 T5484 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 975961 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 975961 T5483 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> 976959 T5486 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 976959 T5486 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 976960 T5486 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 976960 T5486 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 976960 T5486 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 976961 T5486 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-002/collection1/'
   [junit4]   2> 976961 T5486 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-002/collection1/lib/.svn/' to classloader
   [junit4]   2> 976961 T5486 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-002/collection1/lib/classes/' to classloader
   [junit4]   2> 976962 T5486 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-002/collection1/lib/README' to classloader
   [junit4]   2> 976977 T5486 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_10
   [junit4]   2> 976984 T5486 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 976985 T5486 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 976990 T5486 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 977098 T5486 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 977100 T5486 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 977100 T5486 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 977102 T5486 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 977112 T5486 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 977113 T5486 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 977113 T5486 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-002/collection1/, dataDir=./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-001/control/data/
   [junit4]   2> 977113 T5486 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1d9ce02
   [junit4]   2> 977114 T5486 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-001/control/data
   [junit4]   2> 977114 T5486 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-001/control/data/index/
   [junit4]   2> 977114 T5486 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-001/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 977115 T5486 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-001/control/data/index
   [junit4]   2> 977115 T5486 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=20, maxMergeAtOnceExplicit=12, maxMergedSegmentMB=22.6513671875, floorSegmentMB=0.7939453125, forceMergeDeletesPctAllowed=27.974168920704273, segmentsPerTier=34.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 977115 T5486 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1b8593f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@56ddbb),segFN=segments_1,generation=1}
   [junit4]   2> 977116 T5486 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 977117 T5486 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 977117 T5486 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 977118 T5486 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 977118 T5486 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 977118 T5486 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 977118 T5486 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 977118 T5486 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 977119 T5486 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 977119 T5486 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 977119 T5486 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 977119 T5486 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 977119 T5486 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 977120 T5486 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 977120 T5486 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 977120 T5486 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 977120 T5486 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 977122 T5486 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 977123 T5486 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 977123 T5486 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 977123 T5486 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=13, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 977124 T5486 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1b8593f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@56ddbb),segFN=segments_1,generation=1}
   [junit4]   2> 977124 T5486 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 977124 T5486 oass.SolrIndexSearcher.<init> Opening Searcher@1fab628[collection1] main
   [junit4]   2> 977124 T5486 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 977125 T5486 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 977125 T5486 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 977126 T5486 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 977126 T5486 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 977126 T5486 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 977126 T5486 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 977126 T5486 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 977127 T5486 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 977127 T5486 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 977128 T5487 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1fab628[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 977128 T5486 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 977129 T5490 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:36639/_ collection:control_collection shard:shard1
   [junit4]   2> 977129 T5461 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 977129 T5461 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 977130 T5490 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 977130 T5461 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 977131 T5492 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@daad20 name:ZooKeeperConnection Watcher:127.0.0.1:49023/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 977131 T5461 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 977132 T5461 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 977134 T5490 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 977134 T5461 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 977134 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 977135 T5490 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 977135 T5490 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C3014 name=collection1 org.apache.solr.core.SolrCore@1961004 url=http://127.0.0.1:36639/_/collection1 node=127.0.0.1:36639__ C3014_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:36639/_, core=collection1, node_name=127.0.0.1:36639__}
   [junit4]   2> 977135 T5490 C3014 P36639 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:36639/_/collection1/
   [junit4]   2> 977135 T5484 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 977135 T5490 C3014 P36639 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 977136 T5490 C3014 P36639 oasc.SyncStrategy.syncToMe http://127.0.0.1:36639/_/collection1/ has no replicas
   [junit4]   2> 977136 T5490 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:36639/_/collection1/ shard1
   [junit4]   2> 977136 T5490 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 977137 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 977139 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 977140 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 977242 T5492 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> 977243 T5483 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> 977290 T5490 oasc.ZkController.register We are http://127.0.0.1:36639/_/collection1/ and leader is http://127.0.0.1:36639/_/collection1/
   [junit4]   2> 977290 T5490 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:36639/_
   [junit4]   2> 977290 T5490 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 977290 T5490 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 977290 T5490 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 977291 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 977292 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 977292 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 977292 T5490 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 977293 T5484 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 977293 T5484 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:36639/_",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:36639__",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 977295 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 977383 T5461 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 977384 T5461 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 977385 T5461 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57410
   [junit4]   2> 977386 T5461 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 977387 T5461 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 977387 T5461 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-003
   [junit4]   2> 977388 T5461 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-003/'
   [junit4]   2> 977396 T5492 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> 977396 T5483 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> 977405 T5461 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-003/solr.xml
   [junit4]   2> 977433 T5461 oasc.CoreContainer.<init> New CoreContainer 23389601
   [junit4]   2> 977433 T5461 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-003/]
   [junit4]   2> 977434 T5461 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 977434 T5461 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 977434 T5461 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 977435 T5461 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 977435 T5461 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 977435 T5461 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 977436 T5461 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 977436 T5461 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 977437 T5461 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 977438 T5461 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 977439 T5461 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 977439 T5461 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 977440 T5461 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49023/solr
   [junit4]   2> 977441 T5461 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 977442 T5461 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 977443 T5503 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a43893 name:ZooKeeperConnection Watcher:127.0.0.1:49023 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 977444 T5461 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 977445 T5461 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 977446 T5505 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@447416 name:ZooKeeperConnection Watcher:127.0.0.1:49023/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 977447 T5461 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 977453 T5461 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 978457 T5461 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57410__
   [junit4]   2> 978458 T5461 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57410__
   [junit4]   2> 978459 T5483 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 978460 T5505 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 978460 T5492 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 978463 T5506 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 978463 T5506 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 978465 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 978465 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 978465 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 978465 T5506 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 978466 T5484 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 978466 T5484 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:57410/_",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:57410__",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 978467 T5484 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
   [junit4]   2> 978467 T5484 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 978517 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 978618 T5492 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> 978618 T5505 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> 978618 T5483 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> 979466 T5506 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 979466 T5506 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 979467 T5506 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 979467 T5506 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 979468 T5506 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 979468 T5506 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-003/collection1/'
   [junit4]   2> 979468 T5506 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-003/collection1/lib/.svn/' to classloader
   [junit4]   2> 979468 T5506 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-003/collection1/lib/classes/' to classloader
   [junit4]   2> 979469 T5506 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-003/collection1/lib/README' to classloader
   [junit4]   2> 979485 T5506 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_10
   [junit4]   2> 979494 T5506 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 979495 T5506 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 979498 T5506 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 979598 T5506 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 979600 T5506 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 979600 T5506 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 979602 T5506 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 979612 T5506 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 979612 T5506 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 979612 T5506 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-003/collection1/, dataDir=./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-001/jetty1/
   [junit4]   2> 979612 T5506 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1d9ce02
   [junit4]   2> 979613 T5506 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-001/jetty1
   [junit4]   2> 979613 T5506 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-001/jetty1/index/
   [junit4]   2> 979613 T5506 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-001/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 979613 T5506 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-001/jetty1/index
   [junit4]   2> 979614 T5506 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=20, maxMergeAtOnceExplicit=12, maxMergedSegmentMB=22.6513671875, floorSegmentMB=0.7939453125, forceMergeDeletesPctAllowed=27.974168920704273, segmentsPerTier=34.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 979614 T5506 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@d46ca7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@15ea22),segFN=segments_1,generation=1}
   [junit4]   2> 979614 T5506 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 979616 T5506 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 979616 T5506 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 979617 T5506 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 979617 T5506 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 979617 T5506 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 979617 T5506 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 979617 T5506 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 979618 T5506 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 979618 T5506 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 979618 T5506 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 979618 T5506 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 979619 T5506 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 979619 T5506 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 979619 T5506 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 979619 T5506 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 979620 T5506 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 979621 T5506 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 979622 T5506 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 979622 T5506 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 979623 T5506 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=13, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 979623 T5506 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@d46ca7 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@15ea22),segFN=segments_1,generation=1}
   [junit4]   2> 979623 T5506 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 979623 T5506 oass.SolrIndexSearcher.<init> Opening Searcher@1befc85[collection1] main
   [junit4]   2> 979624 T5506 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 979624 T5506 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 979624 T5506 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 979625 T5506 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 979625 T5506 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 979625 T5506 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 979626 T5506 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 979626 T5506 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 979626 T5506 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 979626 T5506 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 979628 T5507 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1befc85[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 979629 T5506 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 979629 T5510 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57410/_ collection:collection1 shard:shard2
   [junit4]   2> 979630 T5461 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 979630 T5461 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 979630 T5510 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 979634 T5510 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 979635 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 979636 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 979636 T5510 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 979636 T5510 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 979636 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> ASYNC  NEW_CORE C3015 name=collection1 org.apache.solr.core.SolrCore@1a6b3d4 url=http://127.0.0.1:57410/_/collection1 node=127.0.0.1:57410__ C3015_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:57410/_, core=collection1, node_name=127.0.0.1:57410__}
   [junit4]   2> 979636 T5510 C3015 P57410 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57410/_/collection1/
   [junit4]   2> 979637 T5510 C3015 P57410 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 979637 T5484 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 979637 T5510 C3015 P57410 oasc.SyncStrategy.syncToMe http://127.0.0.1:57410/_/collection1/ has no replicas
   [junit4]   2> 979637 T5510 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57410/_/collection1/ shard2
   [junit4]   2> 979638 T5510 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 979639 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 979641 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 979644 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 979747 T5492 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> 979747 T5483 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> 979748 T5505 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> 979792 T5510 oasc.ZkController.register We are http://127.0.0.1:57410/_/collection1/ and leader is http://127.0.0.1:57410/_/collection1/
   [junit4]   2> 979792 T5510 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57410/_
   [junit4]   2> 979792 T5510 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 979792 T5510 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 979793 T5510 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 979794 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 979794 T5510 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 979794 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 979794 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 979795 T5484 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 979796 T5484 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:57410/_",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:57410__",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 979797 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 979882 T5461 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 979883 T5461 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 979885 T5461 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53613
   [junit4]   2> 979885 T5461 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 979886 T5461 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 979886 T5461 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-004
   [junit4]   2> 979886 T5461 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-004/'
   [junit4]   2> 979897 T5461 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-004/solr.xml
   [junit4]   2> 979898 T5492 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> 979898 T5505 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> 979898 T5483 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> 979905 T5461 oasc.CoreContainer.<init> New CoreContainer 30882160
   [junit4]   2> 979905 T5461 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-004/]
   [junit4]   2> 979906 T5461 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 979906 T5461 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 979906 T5461 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 979906 T5461 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 979907 T5461 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 979907 T5461 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 979907 T5461 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 979908 T5461 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 979908 T5461 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 979908 T5461 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 979909 T5461 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 979909 T5461 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 979909 T5461 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49023/solr
   [junit4]   2> 979910 T5461 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 979910 T5461 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 979912 T5521 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@af6c4f name:ZooKeeperConnection Watcher:127.0.0.1:49023 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 979912 T5461 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 979913 T5461 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 979914 T5523 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15a3f01 name:ZooKeeperConnection Watcher:127.0.0.1:49023/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 979914 T5461 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 979917 T5461 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 980919 T5461 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53613__
   [junit4]   2> 980921 T5461 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53613__
   [junit4]   2> 980923 T5492 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 980924 T5523 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 980923 T5483 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 980924 T5505 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 980929 T5524 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 980929 T5524 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 980931 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 980931 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 980931 T5524 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 980931 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 980932 T5484 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 980933 T5484 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:53613/_",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53613__",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 980934 T5484 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 980934 T5484 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 980937 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 981040 T5492 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> 981040 T5505 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> 981040 T5523 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> 981040 T5483 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> 981932 T5524 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 981932 T5524 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 981933 T5524 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 981933 T5524 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 981935 T5524 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 981935 T5524 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-004/collection1/'
   [junit4]   2> 981936 T5524 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-004/collection1/lib/.svn/' to classloader
   [junit4]   2> 981937 T5524 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-004/collection1/lib/classes/' to classloader
   [junit4]   2> 981937 T5524 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-004/collection1/lib/README' to classloader
   [junit4]   2> 981965 T5524 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_10
   [junit4]   2> 981995 T5524 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 981997 T5524 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 982005 T5524 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 982123 T5524 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 982124 T5524 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 982125 T5524 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 982127 T5524 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 982139 T5524 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 982139 T5524 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 982140 T5524 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-004/collection1/, dataDir=./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-001/jetty2/
   [junit4]   2> 982140 T5524 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1d9ce02
   [junit4]   2> 982140 T5524 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-001/jetty2
   [junit4]   2> 982140 T5524 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-001/jetty2/index/
   [junit4]   2> 982141 T5524 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-001/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 982141 T5524 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-001/jetty2/index
   [junit4]   2> 982142 T5524 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=20, maxMergeAtOnceExplicit=12, maxMergedSegmentMB=22.6513671875, floorSegmentMB=0.7939453125, forceMergeDeletesPctAllowed=27.974168920704273, segmentsPerTier=34.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 982142 T5524 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1b47c8a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@29681e),segFN=segments_1,generation=1}
   [junit4]   2> 982143 T5524 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 982146 T5524 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 982146 T5524 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 982146 T5524 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 982147 T5524 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 982147 T5524 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 982147 T5524 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 982148 T5524 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 982148 T5524 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 982149 T5524 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 982149 T5524 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 982149 T5524 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 982149 T5524 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 982150 T5524 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 982150 T5524 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 982151 T5524 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 982151 T5524 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 982153 T5524 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 982155 T5524 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 982156 T5524 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 982156 T5524 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=13, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 982157 T5524 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1b47c8a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@29681e),segFN=segments_1,generation=1}
   [junit4]   2> 982157 T5524 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 982158 T5524 oass.SolrIndexSearcher.<init> Opening Searcher@fa175a[collection1] main
   [junit4]   2> 982158 T5524 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 982159 T5524 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 982160 T5524 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 982160 T5524 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 982161 T5524 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 982161 T5524 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 982162 T5524 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 982162 T5524 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 982162 T5524 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 982163 T5524 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 982166 T5525 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@fa175a[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 982168 T5524 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 982169 T5528 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53613/_ collection:collection1 shard:shard3
   [junit4]   2> 982170 T5461 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 982170 T5461 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 982171 T5528 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 982177 T5528 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard3
   [junit4]   2> 982179 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 982180 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 982180 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 982180 T5528 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 982181 T5528 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C3016 name=collection1 org.apache.solr.core.SolrCore@1343ecc url=http://127.0.0.1:53613/_/collection1 node=127.0.0.1:53613__ C3016_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:53613/_, core=collection1, node_name=127.0.0.1:53613__}
   [junit4]   2> 982181 T5528 C3016 P53613 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53613/_/collection1/
   [junit4]   2> 982181 T5528 C3016 P53613 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 982182 T5528 C3016 P53613 oasc.SyncStrategy.syncToMe http://127.0.0.1:53613/_/collection1/ has no replicas
   [junit4]   2> 982182 T5484 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 982182 T5528 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53613/_/collection1/ shard3
   [junit4]   2> 982183 T5528 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
   [junit4]   2> 982189 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 982191 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 982192 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 982295 T5483 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> 982295 T5505 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> 982295 T5523 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> 982295 T5492 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> 982341 T5528 oasc.ZkController.register We are http://127.0.0.1:53613/_/collection1/ and leader is http://127.0.0.1:53613/_/collection1/
   [junit4]   2> 982342 T5528 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53613/_
   [junit4]   2> 982342 T5528 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 982342 T5528 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 982342 T5528 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 982343 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 982343 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 982343 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 982344 T5528 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 982344 T5484 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 982345 T5484 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:53613/_",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53613__",
   [junit4]   2> 	  "shard":"shard3",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 982346 T5483 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 982439 T5461 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
   [junit4]   2> 982439 T5461 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 982442 T5461 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:44932
   [junit4]   2> 982443 T5461 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 982444 T5461 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 982444 T5461 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-005
   [junit4]   2> 982445 T5461 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-005/'
   [junit4]   2> 982449 T5492 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> 982449 T5505 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> 982449 T5523 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> 982449 T5483 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> 982483 T5461 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-005/solr.xml
   [junit4]   2> 982496 T5461 oasc.CoreContainer.<init> New CoreContainer 24233337
   [junit4]   2> 982496 T5461 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.FullSolrCloudDistribCmdsTest-2A25DBBEAD08DE72-001/tempDir-005/]
   [junit4]   2> 982497 T5461 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 982498 T5461 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 982499 T5461 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 982499 T5461 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 982500 T5461 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 982501 T5461 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 982501 T5461 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 982502 T5461 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 982502 T5461 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 982503 T5461 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 982504 T5461 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 982505 T5461 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 982505 T5461 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49023/solr
   [junit4]   2> 982506 T5461 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 982507 T5461 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 982509 T5539 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@80290b name:ZooKeeperConnection Watcher:127.0.0.1:49023 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 982509 T5461 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 982512 T5461 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 982513 T5541 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a727eb name:ZooKeeperConnection Watcher:127.0.0.1:49023/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 982513 T5461 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 982525 T5461 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 983529 T5461 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44932__
   [junit4]   2> 983531 T5461 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:44932__
   [junit4]   2> 983534 T5483 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 983534 T5523 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 983534 T5541 oascc.ZkStateReader$3.process Upd

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

), 8grand0_s=MockFixedIntBlock(blockSize=261), 9grand3_s=MockFixedIntBlock(blockSize=261), 3grand1_s=MockFixedIntBlock(blockSize=261), 19parent_f1_s=MockFixedIntBlock(blockSize=261), 4parent_f1_s=MockFixedIntBlock(blockSize=261), 11grand10_s=PostingsFormat(name=Direct), 14grand8_s=PostingsFormat(name=Direct), 5child3_s=MockFixedIntBlock(blockSize=261), 9parent_f2_s=MockFixedIntBlock(blockSize=261), 14grand12_s=PostingsFormat(name=Lucene41WithOrds), id=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 7child1_s=MockFixedIntBlock(blockSize=261), 13parent_f1_s=PostingsFormat(name=Lucene41WithOrds), 7child0_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 15grand2_s=PostingsFormat(name=Lucene41WithOrds), 23parent_f1_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 8child4_s=MockFixedIntBlock(blockSize=261), 5child2_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 13grand4_s=PostingsFormat(name=Lucene41WithOrds), 29parent_f1_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 33parent_f1_s=MockFixedIntBlock(blockSize=261), 12parent_f1_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 22parent_f1_s=MockFixedIntBlock(blockSize=261), 12grand1_s=PostingsFormat(name=Lucene41WithOrds), 11grand6_s=PostingsFormat(name=Lucene41WithOrds), 2child1_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 32parent_f1_s=PostingsFormat(name=Direct), 3parent_f2_s=PostingsFormat(name=Lucene41WithOrds), 10grand3_s=PostingsFormat(name=Lucene41WithOrds), 6grand3_s=PostingsFormat(name=Direct), 31parent_f2_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 11parent_f2_s=PostingsFormat(name=Direct), 21parent_f2_s=PostingsFormat(name=Lucene41WithOrds), 7grand4_s=PostingsFormat(name=Direct), 3grand0_s=PostingsFormat(name=Direct), 8grand1_s=PostingsFormat(name=Direct), 9grand2_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 9parent_f1_s=PostingsFormat(name=Direct), 14grand9_s=MockFixedIntBlock(blockSize=261), 14grand11_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 13parent_f2_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 23parent_f2_s=MockFixedIntBlock(blockSize=261), 8child5_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 15grand1_s=PostingsFormat(name=Direct), 5child1_s=PostingsFormat(name=Lucene41WithOrds), 14grand0_s=PostingsFormat(name=Direct), 33parent_f2_s=PostingsFormat(name=Direct), 13grand3_s=PostingsFormat(name=Direct), 22parent_f2_s=PostingsFormat(name=Direct), 4child0_s=MockFixedIntBlock(blockSize=261), 11grand5_s=PostingsFormat(name=Direct), 12grand2_s=PostingsFormat(name=Direct), 12parent_f2_s=MockFixedIntBlock(blockSize=261), 10grand4_s=PostingsFormat(name=Direct), 32parent_f2_s=PostingsFormat(name=Lucene41WithOrds), 21parent_f1_s=PostingsFormat(name=Direct), 8grand2_s=PostingsFormat(name=Lucene41WithOrds), 9grand1_s=PostingsFormat(name=Lucene41WithOrds), 12grand8_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 13grand7_s=PostingsFormat(name=Direct), 14parent_f1_s=PostingsFormat(name=Direct), 14grand10_s=MockFixedIntBlock(blockSize=261), 20parent_f2_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 6child4_s=PostingsFormat(name=Lucene41WithOrds), 15grand9_s=PostingsFormat(name=Direct), 6grand0_s=PostingsFormat(name=Lucene41WithOrds), 7child3_s=PostingsFormat(name=Lucene41WithOrds), 15grand0_s=MockFixedIntBlock(blockSize=261), 8child6_s=PostingsFormat(name=Lucene41WithOrds), 5child0_s=PostingsFormat(name=Direct), 14grand1_s=MockFixedIntBlock(blockSize=261), 8parent_f1_s=MockFixedIntBlock(blockSize=261), 15grand13_s=PostingsFormat(name=Lucene41WithOrds), 27parent_f2_s=MockFixedIntBlock(blockSize=261), 2parent_f2_s=PostingsFormat(name=Direct), 4child1_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 11grand4_s=MockFixedIntBlock(blockSize=261), 16parent_f2_s=MockFixedIntBlock(blockSize=261), 10grand5_s=MockFixedIntBlock(blockSize=261), 13grand10_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 7grand6_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 18parent_f1_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 9grand8_s=PostingsFormat(name=Direct), 8grand3_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 6parent_f1_s=PostingsFormat(name=Lucene41WithOrds), 25parent_f1_s=PostingsFormat(name=Direct), 12grand9_s=PostingsFormat(name=Lucene41WithOrds), 0parent_f1_s=MockFixedIntBlock(blockSize=261), 3grand2_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 9grand0_s=PostingsFormat(name=Direct), 4parent_f2_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 13grand6_s=MockFixedIntBlock(blockSize=261), 6child5_s=PostingsFormat(name=Direct), 7child2_s=PostingsFormat(name=Direct), 5grand4_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 6grand1_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 15grand8_s=MockFixedIntBlock(blockSize=261), 8child7_s=PostingsFormat(name=Direct), 16parent_f1_s=PostingsFormat(name=Direct), 14grand2_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 8parent_f2_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 15grand14_s=PostingsFormat(name=Direct), 13grand5_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 29parent_f2_s=PostingsFormat(name=Lucene41WithOrds), 2parent_f1_s=PostingsFormat(name=Lucene41WithOrds), 4child2_s=PostingsFormat(name=Lucene41WithOrds), rnd_b=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 11grand3_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 27parent_f1_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 12grand0_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 10grand6_s=Pulsing41(freqCutoff=11 minBlockSize=76 maxBlockSize=220), 2child0_s=PostingsFormat(name=Lucene41WithOrds), 13grand11_s=PostingsFormat(name=Lucene41WithOrds)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=ar_SY, timezone=America/Argentina/Mendoza
   [junit4]   2> NOTE: Linux 3.8.0-42-generic i386/Oracle Corporation 1.8.0_20-ea (32-bit)/cpus=8,threads=1,free=85863608,total=284909568
   [junit4]   2> NOTE: All tests run in this JVM: [CSVRequestHandlerTest, TestReversedWildcardFilterFactory, SchemaVersionSpecificBehaviorTest, ScriptEngineTest, TestOmitPositions, DirectSolrConnectionTest, TestRealTimeGet, SynonymTokenizerTest, TestChildDocTransformer, TestUpdate, TestRTGBase, TestInitQParser, OutputWriterTest, TestFunctionQuery, SolrInfoMBeanTest, TestBinaryField, TestFileDictionaryLookup, TestPhraseSuggestions, TestIndexSearcher, TestPHPSerializedResponseWriter, PreAnalyzedUpdateProcessorTest, SampleTest, RollingRestartTest, CursorMarkTest, CoreAdminCreateDiscoverTest, UpdateRequestProcessorFactoryTest, TriLevelCompositeIdRoutingTest, TestQuerySenderNoQuery, SpellingQueryConverterTest, AnalysisAfterCoreReloadTest, ConvertedLegacyTest, BasicZkTest, TestLRUCache, TestDocumentBuilder, CacheHeaderTest, TestElisionMultitermQuery, HardAutoCommitTest, FileUtilsTest, SOLR749Test, TestUniqueKeyFieldResource, BadCopyFieldTest, TestNoOpRegenerator, TestHighlightDedupGrouping, TestFastWriter, SSLMigrationTest, ChaosMonkeySafeLeaderTest, TestPostingsSolrHighlighter, TestCollationField, DistribCursorPagingTest, DistributedTermsComponentTest, TestSystemIdResolver, TestSuggestSpellingConverter, TestRandomMergePolicy, TestJoin, TestInfoStreamLogging, LukeRequestHandlerTest, TestDistributedMissingSort, TestDynamicFieldResource, LoggingHandlerTest, RemoteQueryErrorTest, SuggesterFSTTest, DistributedQueryElevationComponentTest, AddSchemaFieldsUpdateProcessorFactoryTest, TermVectorComponentTest, TestXIncludeConfig, DirectUpdateHandlerOptimizeTest, SearchHandlerTest, NumericFieldsTest, AtomicUpdatesTest, TestQueryTypes, DocValuesMissingTest, ZkSolrClientTest, TestLFUCache, HdfsWriteToMultipleCollectionsTest, TestCSVResponseWriter, SolrIndexConfigTest, TestCSVLoader, SystemInfoHandlerTest, TestExtendedDismaxParser, TestRandomFaceting, DebugComponentTest, QueryParsingTest, TestSchemaResource, TestStressLucene, TestReloadAndDeleteDocs, BinaryUpdateRequestHandlerTest, TestDistributedGrouping, QueryElevationComponentTest, ShardRoutingCustomTest, HdfsCollectionsAPIDistributedZkTest, TestFiltering, FieldAnalysisRequestHandlerTest, RequestHandlersTest, SoftAutoCommitTest, CollectionsAPIDistributedZkTest, TestFieldTypeResource, BlockCacheTest, TestFieldResource, OverseerStatusTest, OverseerTest, LeaderElectionIntegrationTest, FullSolrCloudDistribCmdsTest]
   [junit4] Completed on J1 in 74.27s, 1 test, 1 error <<< FAILURES!

[...truncated 591 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:447: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:496: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1299: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:923: There were test failures: 405 suites, 1656 tests, 1 error, 37 ignored (16 assumptions)

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