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/03/16 09:09:24 UTC

[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.7.0) - Build # 1414 - Still Failing!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/1414/
Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseG1GC -XX:-UseSuperWord

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

Error Message:
Timeout occured while waiting response from server at: http://127.0.0.1:57984/t_/o

Stack Trace:
org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://127.0.0.1:57984/t_/o
	at __randomizedtesting.SeedInfo.seed([3CF36532894738DF:BD15EB2AFE1858E3]:0)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:512)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:203)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:199)
	at org.apache.solr.cloud.ShardSplitTest.splitShard(ShardSplitTest.java:525)
	at org.apache.solr.cloud.ShardSplitTest.incompleteOrOverlappingCustomRangeTest(ShardSplitTest.java:148)
	at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:100)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:870)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1617)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
	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:70)
	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:359)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
	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 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:70)
	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:359)
	at java.lang.Thread.run(Thread.java:744)
Caused by: java.net.SocketTimeoutException: Read timed out
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.read(SocketInputStream.java:152)
	at java.net.SocketInputStream.read(SocketInputStream.java:122)
	at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:160)
	at org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:84)
	at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:273)
	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140)
	at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)
	at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:260)
	at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:283)
	at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:251)
	at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:197)
	at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:271)
	at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:123)
	at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:682)
	at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:486)
	at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:863)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106)
	at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:57)
	at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:402)
	... 45 more




Build Log:
[...truncated 10959 lines...]
   [junit4] Suite: org.apache.solr.cloud.ShardSplitTest
   [junit4]   2> 3391736 T10943 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /t_/o
   [junit4]   2> 3391744 T10943 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-ShardSplitTest-1394954921334
   [junit4]   2> 3391748 T10943 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 3391751 T10944 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 3391852 T10943 oasc.ZkTestServer.run start zk server on port:57977
   [junit4]   2> 3391855 T10943 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3391867 T10950 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@58a0aa31 name:ZooKeeperConnection Watcher:127.0.0.1:57977 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3391868 T10943 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3391869 T10943 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 3391889 T10943 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3391897 T10952 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5500db71 name:ZooKeeperConnection Watcher:127.0.0.1:57977/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3391898 T10943 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3391898 T10943 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 3391912 T10943 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 3391925 T10943 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 3391935 T10943 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 3391948 T10943 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 3391949 T10943 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 3391970 T10943 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
   [junit4]   2> 3391972 T10943 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 3391993 T10943 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 3391996 T10943 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 3392007 T10943 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 3392009 T10943 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 3392017 T10943 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 3392018 T10943 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 3392023 T10943 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 3392024 T10943 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 3392030 T10943 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 3392031 T10943 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 3392037 T10943 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 3392037 T10943 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 3392044 T10943 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 3392044 T10943 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 3392051 T10943 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 3392052 T10943 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 3392060 T10943 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 3392060 T10943 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 3393227 T10943 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 3393231 T10943 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57980
   [junit4]   2> 3393232 T10943 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 3393232 T10943 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 3393232 T10943 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ShardSplitTest-controljetty-1394954921658
   [junit4]   2> 3393233 T10943 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-controljetty-1394954921658/'
   [junit4]   2> 3393268 T10943 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1394954921658/solr.xml
   [junit4]   2> 3393342 T10943 oasc.CoreContainer.<init> New CoreContainer 1253093754
   [junit4]   2> 3393343 T10943 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ShardSplitTest-controljetty-1394954921658/]
   [junit4]   2> 3393345 T10943 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 3393345 T10943 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 3393345 T10943 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 3393346 T10943 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 3393346 T10943 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 3393346 T10943 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 3393347 T10943 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 3393347 T10943 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 3393347 T10943 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 3393347 T10943 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 3393348 T10943 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 3393348 T10943 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 3393349 T10943 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57977/solr
   [junit4]   2> 3393349 T10943 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 3393350 T10943 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3393354 T10963 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1653e6e5 name:ZooKeeperConnection Watcher:127.0.0.1:57977 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3393354 T10943 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3393357 T10943 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3393361 T10965 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@225e7731 name:ZooKeeperConnection Watcher:127.0.0.1:57977/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3393361 T10943 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3393365 T10943 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 3393373 T10943 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 3393382 T10943 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 3393390 T10943 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 3393401 T10943 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 3393408 T10943 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 3393411 T10943 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57980_t_%2Fo
   [junit4]   2> 3393413 T10943 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57980_t_%2Fo
   [junit4]   2> 3393420 T10943 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 3393425 T10943 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 3393432 T10943 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:57980_t_%2Fo
   [junit4]   2> 3393432 T10943 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 3393437 T10943 oasc.Overseer.start Overseer (id=91419765725331459-127.0.0.1:57980_t_%2Fo-n_0000000000) starting
   [junit4]   2> 3393446 T10943 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 3393473 T10967 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 3393474 T10943 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 3393474 T10967 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 3393478 T10943 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 3393482 T10943 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 3393488 T10966 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 3393496 T10968 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 3393496 T10968 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 3393498 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3393498 T10968 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 3393502 T10966 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3393503 T10966 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:57980/t_/o",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:57980_t_%2Fo",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 3393504 T10966 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 3393504 T10966 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 3393509 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3393511 T10965 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> 3394500 T10968 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 3394501 T10968 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ShardSplitTest-controljetty-1394954921658/collection1
   [junit4]   2> 3394501 T10968 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 3394504 T10968 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 3394504 T10968 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 3394509 T10968 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 3394509 T10968 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-controljetty-1394954921658/collection1/'
   [junit4]   2> 3394513 T10968 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1394954921658/collection1/lib/.svn/' to classloader
   [junit4]   2> 3394514 T10968 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1394954921658/collection1/lib/classes/' to classloader
   [junit4]   2> 3394515 T10968 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1394954921658/collection1/lib/README' to classloader
   [junit4]   2> 3394586 T10968 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 3394648 T10968 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 3394653 T10968 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 3394659 T10968 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 3395289 T10968 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 3395293 T10968 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 3395295 T10968 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 3395302 T10968 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 3395389 T10968 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 3395390 T10968 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ShardSplitTest-controljetty-1394954921658/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1394954921332/control/data/
   [junit4]   2> 3395390 T10968 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@420cd195
   [junit4]   2> 3395390 T10968 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1394954921332/control/data
   [junit4]   2> 3395390 T10968 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1394954921332/control/data/index/
   [junit4]   2> 3395391 T10968 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1394954921332/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 3395391 T10968 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1394954921332/control/data/index
   [junit4]   2> 3395391 T10968 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=37, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=89.8056640625, floorSegmentMB=1.4814453125, forceMergeDeletesPctAllowed=19.51342834405806, segmentsPerTier=45.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.583908990334402
   [junit4]   2> 3395392 T10968 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@20c68155 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@13afa61c),segFN=segments_1,generation=1}
   [junit4]   2> 3395392 T10968 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 3395397 T10968 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 3395398 T10968 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 3395398 T10968 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 3395398 T10968 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 3395399 T10968 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 3395399 T10968 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 3395400 T10968 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 3395400 T10968 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 3395400 T10968 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 3395401 T10968 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 3395401 T10968 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 3395402 T10968 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 3395402 T10968 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 3395402 T10968 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 3395403 T10968 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 3395403 T10968 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 3395404 T10968 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 3395414 T10968 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 3395419 T10968 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 3395420 T10968 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 3395420 T10968 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=27, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5545788843633268]
   [junit4]   2> 3395421 T10968 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@20c68155 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@13afa61c),segFN=segments_1,generation=1}
   [junit4]   2> 3395421 T10968 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 3395421 T10968 oass.SolrIndexSearcher.<init> Opening Searcher@33723c5e[collection1] main
   [junit4]   2> 3395421 T10968 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 3395423 T10968 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 3395424 T10968 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 3395425 T10968 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 3395425 T10968 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 3395425 T10968 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3395427 T10968 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 3395427 T10968 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3395427 T10968 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 3395427 T10968 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 3395431 T10969 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@33723c5e[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 3395432 T10968 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 3395433 T10943 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 3395434 T10943 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 3395433 T10972 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57980/t_/o collection:control_collection shard:shard1
   [junit4]   2> 3395435 T10943 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3395436 T10972 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 3395440 T10974 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2f9da1da name:ZooKeeperConnection Watcher:127.0.0.1:57977/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3395440 T10943 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3395443 T10943 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 3395448 T10943 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 3395450 T10972 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 3395453 T10972 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 3395453 T10972 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C3962 name=collection1 org.apache.solr.core.SolrCore@4cc064c5 url=http://127.0.0.1:57980/t_/o/collection1 node=127.0.0.1:57980_t_%2Fo C3962_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:57980/t_/o, core=collection1, node_name=127.0.0.1:57980_t_%2Fo}
   [junit4]   2> 3395453 T10972 C3962 P57980 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57980/t_/o/collection1/
   [junit4]   2> 3395454 T10972 C3962 P57980 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 3395454 T10972 C3962 P57980 oasc.SyncStrategy.syncToMe http://127.0.0.1:57980/t_/o/collection1/ has no replicas
   [junit4]   2> 3395454 T10972 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57980/t_/o/collection1/ shard1
   [junit4]   2> 3395454 T10972 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 3395458 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3395464 T10966 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3395472 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3395475 T10965 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> 3395478 T10974 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> 3395486 T10966 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3395492 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3395605 T10965 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> 3395605 T10974 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> 3395625 T10972 oasc.ZkController.register We are http://127.0.0.1:57980/t_/o/collection1/ and leader is http://127.0.0.1:57980/t_/o/collection1/
   [junit4]   2> 3395625 T10972 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57980/t_/o
   [junit4]   2> 3395625 T10972 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 3395626 T10972 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 3395626 T10972 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 3395629 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3395630 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3395630 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3395633 T10972 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3395636 T10966 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3395637 T10966 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:57980/t_/o",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:57980_t_%2Fo",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 3395642 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3395747 T10965 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> 3395748 T10974 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> 3396605 T10943 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 3396606 T10943 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 3396609 T10943 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57984
   [junit4]   2> 3396609 T10943 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 3396610 T10943 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 3396610 T10943 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1394954925035
   [junit4]   2> 3396610 T10943 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1394954925035/'
   [junit4]   2> 3396645 T10943 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1394954925035/solr.xml
   [junit4]   2> 3396714 T10943 oasc.CoreContainer.<init> New CoreContainer 900192790
   [junit4]   2> 3396714 T10943 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1394954925035/]
   [junit4]   2> 3396716 T10943 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 3396716 T10943 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 3396716 T10943 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 3396716 T10943 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 3396717 T10943 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 3396717 T10943 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 3396717 T10943 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 3396717 T10943 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 3396718 T10943 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 3396718 T10943 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 3396719 T10943 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 3396719 T10943 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 3396720 T10943 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57977/solr
   [junit4]   2> 3396720 T10943 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 3396721 T10943 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3396726 T10985 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1edef5df name:ZooKeeperConnection Watcher:127.0.0.1:57977 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3396726 T10943 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3396731 T10943 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3396736 T10987 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@674cd4c0 name:ZooKeeperConnection Watcher:127.0.0.1:57977/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3396736 T10943 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3396753 T10943 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 3397762 T10943 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57984_t_%2Fo
   [junit4]   2> 3397767 T10943 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57984_t_%2Fo
   [junit4]   2> 3397778 T10965 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 3397779 T10974 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 3397779 T10987 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 3397811 T10988 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 3397812 T10988 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 3397816 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3397816 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3397816 T10988 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 3397816 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3397820 T10966 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3397822 T10966 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:57984/t_/o",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:57984_t_%2Fo",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 3397822 T10966 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 3397822 T10966 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 3397828 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3397830 T10965 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> 3397830 T10974 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> 3397830 T10987 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> 3398817 T10988 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 3398818 T10988 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1394954925035/collection1
   [junit4]   2> 3398819 T10988 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 3398821 T10988 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 3398821 T10988 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 3398826 T10988 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 3398826 T10988 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1394954925035/collection1/'
   [junit4]   2> 3398831 T10988 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1394954925035/collection1/lib/.svn/' to classloader
   [junit4]   2> 3398832 T10988 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1394954925035/collection1/lib/classes/' to classloader
   [junit4]   2> 3398833 T10988 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1394954925035/collection1/lib/README' to classloader
   [junit4]   2> 3398914 T10988 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 3398975 T10988 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 3398979 T10988 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 3398986 T10988 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 3399546 T10988 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 3399550 T10988 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 3399551 T10988 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 3399558 T10988 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 3399612 T10988 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 3399612 T10988 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1394954925035/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1394954921332/jetty1/
   [junit4]   2> 3399613 T10988 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@420cd195
   [junit4]   2> 3399614 T10988 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1394954921332/jetty1
   [junit4]   2> 3399614 T10988 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1394954921332/jetty1/index/
   [junit4]   2> 3399614 T10988 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1394954921332/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 3399615 T10988 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1394954921332/jetty1/index
   [junit4]   2> 3399615 T10988 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=37, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=89.8056640625, floorSegmentMB=1.4814453125, forceMergeDeletesPctAllowed=19.51342834405806, segmentsPerTier=45.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.583908990334402
   [junit4]   2> 3399616 T10988 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@6c091426 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@26077231),segFN=segments_1,generation=1}
   [junit4]   2> 3399617 T10988 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 3399624 T10988 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 3399624 T10988 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 3399625 T10988 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 3399625 T10988 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 3399625 T10988 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 3399626 T10988 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 3399626 T10988 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 3399627 T10988 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 3399627 T10988 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 3399628 T10988 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 3399629 T10988 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 3399629 T10988 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 3399630 T10988 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 3399631 T10988 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 3399632 T10988 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 3399633 T10988 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 3399633 T10988 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 3399642 T10988 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 3399646 T10988 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 3399646 T10988 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 3399646 T10988 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=27, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5545788843633268]
   [junit4]   2> 3399647 T10988 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@6c091426 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@26077231),segFN=segments_1,generation=1}
   [junit4]   2> 3399647 T10988 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 3399647 T10988 oass.SolrIndexSearcher.<init> Opening Searcher@299ed906[collection1] main
   [junit4]   2> 3399648 T10988 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 3399651 T10988 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 3399652 T10988 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 3399653 T10988 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 3399653 T10988 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 3399654 T10988 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3399656 T10988 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 3399656 T10988 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3399657 T10988 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 3399657 T10988 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 3399664 T10989 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@299ed906[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 3399667 T10988 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 3399668 T10943 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 3399668 T10943 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 3399668 T10992 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57984/t_/o collection:collection1 shard:shard1
   [junit4]   2> 3399670 T10992 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 3399683 T10992 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 3399686 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3399689 T10966 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3399691 T10992 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 3399691 T10992 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C3963 name=collection1 org.apache.solr.core.SolrCore@6bcf2185 url=http://127.0.0.1:57984/t_/o/collection1 node=127.0.0.1:57984_t_%2Fo C3963_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:57984/t_/o, core=collection1, node_name=127.0.0.1:57984_t_%2Fo}
   [junit4]   2> 3399692 T10992 C3963 P57984 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57984/t_/o/collection1/
   [junit4]   2> 3399692 T10992 C3963 P57984 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 3399692 T10992 C3963 P57984 oasc.SyncStrategy.syncToMe http://127.0.0.1:57984/t_/o/collection1/ has no replicas
   [junit4]   2> 3399692 T10992 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57984/t_/o/collection1/ shard1
   [junit4]   2> 3399692 T10992 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 3399699 T10987 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> 3399700 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3399706 T10965 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> 3399712 T10974 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> 3399714 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3399716 T10966 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3399721 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3399825 T10987 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> 3399826 T10974 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> 3399826 T10965 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> 3399867 T10992 oasc.ZkController.register We are http://127.0.0.1:57984/t_/o/collection1/ and leader is http://127.0.0.1:57984/t_/o/collection1/
   [junit4]   2> 3399867 T10992 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57984/t_/o
   [junit4]   2> 3399867 T10992 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 3399868 T10992 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 3399868 T10992 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 3399870 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3399871 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3399871 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3399872 T10992 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3399875 T10966 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3399875 T10966 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:57984/t_/o",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:57984_t_%2Fo",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 3399883 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3399987 T10965 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> 3399988 T10974 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> 3399988 T10987 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> 3400811 T10943 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 3400812 T10943 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 3400816 T10943 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57987
   [junit4]   2> 3400816 T10943 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 3400816 T10943 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 3400817 T10943 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1394954929256
   [junit4]   2> 3400817 T10943 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1394954929256/'
   [junit4]   2> 3400849 T10943 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1394954929256/solr.xml
   [junit4]   2> 3400930 T10943 oasc.CoreContainer.<init> New CoreContainer 1642870381
   [junit4]   2> 3400931 T10943 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1394954929256/]
   [junit4]   2> 3400933 T10943 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 3400933 T10943 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 3400933 T10943 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 3400933 T10943 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 3400933 T10943 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 3400934 T10943 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 3400934 T10943 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 3400934 T10943 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 3400935 T10943 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 3400935 T10943 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 3400935 T10943 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 3400936 T10943 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 3400936 T10943 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57977/solr
   [junit4]   2> 3400936 T10943 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 3400938 T10943 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3400942 T11003 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5ae96054 name:ZooKeeperConnection Watcher:127.0.0.1:57977 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3400943 T10943 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3400948 T10943 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3400952 T11005 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8cc00b0 name:ZooKeeperConnection Watcher:127.0.0.1:57977/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3400953 T10943 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3400969 T10943 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 3401978 T10943 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57987_t_%2Fo
   [junit4]   2> 3401982 T10943 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57987_t_%2Fo
   [junit4]   2> 3401994 T10987 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 3401995 T10974 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 3401995 T11005 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 3401995 T10965 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 3402027 T11006 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 3402028 T11006 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 3402029 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3402030 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3402030 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3402030 T11006 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 3402034 T10966 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3402035 T10966 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:57987/t_/o",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:57987_t_%2Fo",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 3402035 T10966 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 3402036 T10966 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 3402041 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3402042 T10965 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> 3402042 T11005 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> 3402043 T10987 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> 3402043 T10974 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> 3403032 T11006 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 3403032 T11006 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1394954929256/collection1
   [junit4]   2> 3403034 T11006 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 3403036 T11006 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 3403037 T11006 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 3403041 T11006 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 3403042 T11006 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1394954929256/collection1/'
   [junit4]   2> 3403044 T11006 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1394954929256/collection1/lib/.svn/' to classloader
   [junit4]   2> 3403045 T11006 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1394954929256/collection1/lib/classes/' to classloader
   [junit4]   2> 3403046 T11006 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1394954929256/collection1/lib/README' to classloader
   [junit4]   2> 3403114 T11006 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 3403222 T11006 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 3403226 T11006 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 3403239 T11006 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 3403783 T11006 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 3403787 T11006 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 3403789 T11006 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 3403795 T11006 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 3403860 T11006 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 3403861 T11006 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1394954929256/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1394954921332/jetty2/
   [junit4]   2> 3403862 T11006 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@420cd195
   [junit4]   2> 3403863 T11006 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1394954921332/jetty2
   [junit4]   2> 3403863 T11006 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1394954921332/jetty2/index/
   [junit4]   2> 3403863 T11006 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1394954921332/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 3403864 T11006 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1394954921332/jetty2/index
   [junit4]   2> 3403864 T11006 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=37, maxMergeAtOnceExplicit=38, maxMergedSegmentMB=89.8056640625, floorSegmentMB=1.4814453125, forceMergeDeletesPctAllowed=19.51342834405806, segmentsPerTier=45.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.583908990334402
   [junit4]   2> 3403865 T11006 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@3c004ba9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@323b0072),segFN=segments_1,generation=1}
   [junit4]   2> 3403865 T11006 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 3403872 T11006 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 3403872 T11006 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 3403872 T11006 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 3403873 T11006 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 3403873 T11006 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 3403874 T11006 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 3403874 T11006 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 3403874 T11006 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 3403875 T11006 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 3403875 T11006 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 3403876 T11006 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 3403876 T11006 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 3403876 T11006 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 3403877 T11006 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 3403877 T11006 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 3403878 T11006 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 3403879 T11006 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 3403894 T11006 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 3403901 T11006 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 3403901 T11006 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 3403902 T11006 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=27, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5545788843633268]
   [junit4]   2> 3403902 T11006 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@3c004ba9 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@323b0072),segFN=segments_1,generation=1}
   [junit4]   2> 3403902 T11006 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 3403903 T11006 oass.SolrIndexSearcher.<init> Opening Searcher@3217715f[collection1] main
   [junit4]   2> 3403903 T11006 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 3403906 T11006 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 3403906 T11006 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 3403910 T11006 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 3403910 T11006 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 3403910 T11006 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3403914 T11006 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 3403915 T11006 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 3403915 T11006 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 3403916 T11006 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 3403924 T11007 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3217715f[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 3403931 T11006 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 3403934 T10943 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 3403934 T10943 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 3403934 T11010 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57987/t_/o collection:collection1 shard:shard2
   [junit4]   2> 3403937 T11010 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 3403946 T11010 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 3403950 T11010 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 3403950 T11010 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C3964 name=collection1 org.apache.solr.core.SolrCore@232b165d url=http://127.0.0.1:57987/t_/o/collection1 node=127.0.0.1:57987_t_%2Fo C3964_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:57987/t_/o, core=collection1, node_name=127.0.0.1:57987_t_%2Fo}
   [junit4]   2> 3403950 T11010 C3964 P57987 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57987/t_/o/collection1/
   [junit4]   2> 3403950 T11010 C3964 P57987 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 3403950 T11010 C3964 P57987 oasc.SyncStrategy.syncToMe http://127.0.0.1:57987/t_/o/collection1/ has no replicas
   [junit4]   2> 3403951 T11010 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57987/t_/o/collection1/ shard2
   [junit4]   2> 3403951 T11010 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 3403956 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3403961 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3403962 T10966 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3403971 T10965 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> 3403972 T10974 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> 3403972 T11005 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> 3403973 T10987 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> 3403981 T10966 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3403985 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3404090 T11005 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> 3404092 T10965 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> 3404092 T10987 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> 3404096 T10974 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> 3404117 T11010 oasc.ZkController.register We are http://127.0.0.1:57987/t_/o/collection1/ and leader is http://127.0.0.1:57987/t_/o/collection1/
   [junit4]   2> 3404117 T11010 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57987/t_/o
   [junit4]   2> 3404117 T11010 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 3404117 T11010 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 3404118 T11010 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 3404124 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3404125 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3404125 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3404129 T10966 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3404130 T10966 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:57987/t_/o",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:57987_t_%2Fo",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 3404131 T11010 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 3404134 T10965 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 3404248 T11005 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> 3404249 T10965 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> 3404249 T10974 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> 3404256 T10987 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> 3405117 T10943 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
   [junit4]   2> 3405118 T10943 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 3405121 T10943 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57990
   [junit4]   2> 3405122 T10943 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 3405122 T10943 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 3405122 T10943 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ShardSplitTest-jetty3-1394954933522
   [junit4]   2> 3405122 T10943 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty3-1394954933522/'
   [junit4]   2> 3405162 T10943 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1394954933522/solr.xml
   [junit4]   2> 3405233 T10943 oasc.CoreContainer.<init> New CoreContainer 1825699118
   [junit4]   2> 3405233 T10943 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ShardSplitTest-jetty3-1394954933522/]
   [junit4]   2> 3405235 T10943 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 3405235 T10943 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 3405235 T10943 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 3405235 T10943 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 3405236 T10943 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 3405236 T10943 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 3405236 T10943 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 3405238 T10943 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 3405238 T10943 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 3405238 T10943 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 3405239 T10943 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 3405239 T10943 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 3405239 T10943 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57977/solr
   [junit4]   2> 3405240 T10943 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 3405241 T10943 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3405247 T11021 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4c37d6d2 name:ZooKeeperConnection Watcher:127.0.0.1:57977 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3405248 T10943 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3405252 T10943 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 3405256 T11023 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7f8c6c8a name:ZooKeeperConnection Watcher:127.0.0.1:57977/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 3405257 T10943 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 3405275 T10943 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 3406284 T10943 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57990_t_%2Fo
   [junit4]   2> 3406292 T10943 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0

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

ception.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:259)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:256)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=zh_CN, timezone=Asia/Calcutta
   [junit4]   2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.7.0_51 (64-bit)/cpus=2,threads=1,free=126050640,total=536870912
   [junit4]   2> NOTE: All tests run in this JVM: [NotRequiredUniqueKeyTest, TestXIncludeConfig, PluginInfoTest, TestFieldSortValues, SliceStateTest, TermVectorComponentDistributedTest, TestFoldingMultitermQuery, CSVRequestHandlerTest, DisMaxRequestHandlerTest, LoggingHandlerTest, SpellCheckCollatorTest, MoreLikeThisHandlerTest, SolrTestCaseJ4Test, ExpressionTest, TestStressUserVersions, TestDocBasedVersionConstraints, NoFacetTest, TestSchemaSimilarityResource, FullSolrCloudDistribCmdsTest, DirectUpdateHandlerOptimizeTest, SearchHandlerTest, EchoParamsTest, LeaderElectionTest, TestSolrDeletionPolicy2, MultiTermTest, TestExpandComponent, TestCoreContainer, TestSolrXMLSerializer, QueryFacetTest, TestManagedSchemaFieldResource, TestSolrQueryParser, DistributedSuggestComponentTest, TestManagedResourceStorage, DateFieldTest, HighlighterConfigTest, DistributedQueryComponentCustomSortTest, JsonLoaderTest, DefaultValueUpdateProcessorTest, TestNumberUtils, ZkNodePropsTest, LukeRequestHandlerTest, EnumFieldTest, TestOmitPositions, TestPHPSerializedResponseWriter, TestComponentsName, TestConfig, OverseerRolesTest, MigrateRouteKeyTest, ReturnFieldsTest, TriLevelCompositeIdRoutingTest, TestUniqueKeyFieldResource, RangeFacetTest, DistributedExpandComponentTest, UpdateParamsTest, DocValuesMultiTest, DocValuesTest, TestRecoveryHdfs, SolrIndexSplitterTest, TestWriterPerf, HdfsRecoveryZkTest, BinaryUpdateRequestHandlerTest, TestUtils, TestManagedSchema, TestSolrJ, TestCSVLoader, CursorMarkTest, BadIndexSchemaTest, TestSolrQueryParserDefaultOperatorResource, TestStandardQParsers, TestFastOutputStream, AbstractAnalyticsFacetTest, TestFunctionQuery, DirectSolrSpellCheckerTest, DOMUtilTest, TestSolr4Spatial, BasicFunctionalityTest, XsltUpdateRequestHandlerTest, TestBinaryResponseWriter, SuggesterFSTTest, TestStressRecovery, TestQuerySenderNoQuery, FileBasedSpellCheckerTest, MinimalSchemaTest, TestRestManager, TestSolrIndexConfig, SampleTest, CoreMergeIndexesAdminHandlerTest, FieldMutatingUpdateProcessorTest, TestCloudManagedSchema, ZkCLITest, TestSweetSpotSimilarityFactory, TestSolrQueryParserResource, TestRangeQuery, CachingDirectoryFactoryTest, CircularListTest, JSONWriterTest, StressHdfsTest, TermVectorComponentTest, SolrPluginUtilsTest, PreAnalyzedFieldTest, TestStressReorder, TestCharFilters, TestPseudoReturnFields, RAMDirectoryFactoryTest, TestRTGBase, ConnectionManagerTest, TestFastLRUCache, SuggesterTest, BadCopyFieldTest, TestHighlightDedupGrouping, BasicDistributedZk2Test, SchemaVersionSpecificBehaviorTest, CursorPagingTest, TestLFUCache, QueryResultKeyTest, TestFuzzyAnalyzedSuggestions, ChaosMonkeyNothingIsSafeTest, TestCodecSupport, PrimitiveFieldTypeTest, TestInitQParser, TestIndexSearcher, TestMaxScoreQueryParser, SolrCoreCheckLockOnStartupTest, TestLuceneMatchVersion, TestCoreDiscovery, DocValuesMissingTest, PreAnalyzedUpdateProcessorTest, OpenExchangeRatesOrgProviderTest, ClusterStateUpdateTest, SpellCheckComponentTest, TestFastWriter, DistributedTermsComponentTest, TestStressLucene, LegacyHTMLStripCharFilterTest, ResourceLoaderTest, TestImplicitCoreProperties, SystemInfoHandlerTest, TestNoOpRegenerator, ClusterStateTest, StandardRequestHandlerTest, DirectSolrConnectionTest, QueryParsingTest, UnloadDistributedZkTest, TestBM25SimilarityFactory, TestElisionMultitermQuery, TestMergePolicyConfig, DistributedDebugComponentTest, StatelessScriptUpdateProcessorFactoryTest, AbstractAnalyticsStatsTest, CollectionsAPIDistributedZkTest, BJQParserTest, TestOverriddenPrefixQueryForCustomFieldType, TestReversedWildcardFilterFactory, TestPerFieldSimilarity, SynonymTokenizerTest, TermsComponentTest, ShardRoutingTest, HdfsBasicDistributedZk2Test, HdfsBasicDistributedZkTest, SolrXmlInZkTest, OverseerCollectionProcessorTest, TestFieldTypeCollectionResource, CacheHeaderTest, UpdateRequestProcessorFactoryTest, ModifyConfFileTest, AsyncMigrateRouteKeyTest, SliceStateUpdateTest, TestNRTOpen, WordBreakSolrSpellCheckerTest, TestIBSimilarityFactory, NumericFieldsTest, TestRealTimeGet, TestLazyCores, SimplePostToolTest, TestReplicationHandler, DeleteInactiveReplicaTest, TestLMJelinekMercerSimilarityFactory, SolrRequestParserTest, RecoveryZkTest, TestBlendedInfixSuggestions, TestFieldTypeResource, CoreContainerCoreInitFailuresTest, DistributedQueryComponentOptimizationTest, FastVectorHighlighterTest, CurrencyFieldOpenExchangeTest, SolrCmdDistributorTest, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, SyncSliceTest, OpenCloseCoreStressTest, OverseerTest, LeaderElectionIntegrationTest, BasicZkTest, TestRandomFaceting, ZkSolrClientTest, TestZkChroot, TestRandomDVFaceting, ShardRoutingCustomTest, TestDistributedSearch, AutoCommitTest, TestDistributedGrouping, TestFaceting, TestRecovery, TestHashPartitioner, DistributedSpellCheckComponentTest, ZkControllerTest, TestJoin, TestMultiCoreConfBootstrap, TestReload, TestStressVersions, HardAutoCommitTest, SimpleFacetsTest, SolrCoreTest, StatsComponentTest, TestGroupingSearch, QueryElevationComponentTest, PeerSyncTest, ConvertedLegacyTest, TestSort, TestFiltering, DirectUpdateHandlerTest, TestBadConfig, HighlighterTest, SoftAutoCommitTest, ShowFileRequestHandlerTest, DistributedQueryElevationComponentTest, CurrencyFieldXmlFileTest, AnalysisAfterCoreReloadTest, SignatureUpdateProcessorFactoryTest, TestExtendedDismaxParser, CoreAdminHandlerTest, SuggesterTSTTest, TestTrie, SpatialFilterTest, SuggesterWFSTTest, PolyFieldTest, NoCacheHeaderTest, TestUpdate, TestAtomicUpdateErrorCases, TestWordDelimiterFilterFactory, QueryEqualityTest, SortByFunctionTest, TestRemoteStreaming, DistanceFunctionTest, TestSolrDeletionPolicy1, SolrInfoMBeanTest, DebugComponentTest, IndexBasedSpellCheckerTest, TestSurroundQueryParser, TestQueryUtils, DocumentAnalysisRequestHandlerTest, TestQueryTypes, XmlUpdateRequestHandlerTest, RequestHandlersTest, DocumentBuilderTest, TestValueSourceCache, PathHierarchyTokenizerFactoryTest, TestIndexingPerformance, RequiredFieldsTest, FieldAnalysisRequestHandlerTest, TestArbitraryIndexDir, IndexSchemaRuntimeFieldTest, RegexBoostProcessorTest, IndexSchemaTest, TestJmxIntegration, TestCollationField, TestCSVResponseWriter, MBeansHandlerTest, TestAnalyzedSuggestions, UniqFieldsUpdateProcessorFactoryTest, TestPartialUpdateDeduplication, PingRequestHandlerTest, SOLR749Test, TestQuerySenderListener, AlternateDirectoryTest, CopyFieldTest, ResponseLogComponentTest, SolrIndexConfigTest, BadComponentTest, TestDocSet, TestBinaryField, TestSearchPerf, OutputWriterTest, ExternalFileFieldSortTest, TestSolrCoreProperties, TestPostingsSolrHighlighter, TestPhraseSuggestions, SpellPossibilityIteratorTest, TestDFRSimilarityFactory, TestLMDirichletSimilarityFactory, TestDefaultSimilarityFactory, TestJmxMonitoredMap, TimeZoneUtilsTest, ScriptEngineTest, URLClassifyProcessorTest, DateMathParserTest, TestSystemIdResolver, PrimUtilsTest, TestSuggestSpellingConverter, SpellingQueryConverterTest, TestLRUCache, TestDocumentBuilder, UUIDFieldTest, FileUtilsTest, TestCursorMarkWithoutUniqueKey, TestDistributedMissingSort, FieldFacetExtrasTest, FunctionTest, AliasIntegrationTest, AssignTest, CollectionsAPIAsyncDistributedZkTest, CustomCollectionTest, DeleteReplicaTest, DeleteShardTest, DistribCursorPagingTest, RemoteQueryErrorTest, ShardSplitTest]
   [junit4] Completed in 330.99s, 1 test, 1 error <<< FAILURES!

[...truncated 184 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:467: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:447: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:45: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/common-build.xml:490: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1275: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:907: There were test failures: 387 suites, 1634 tests, 1 error, 54 ignored (27 assumptions)

Total time: 98 minutes 14 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseG1GC -XX:-UseSuperWord
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure