You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/08/26 05:46:08 UTC
[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.8.0) - Build # 1791
- Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/1791/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseG1GC
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:50247/qfv
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: Timeout occured while waiting response from server at: http://127.0.0.1:50247/qfv
at __randomizedtesting.SeedInfo.seed([3311E92FF1C33D00:B2F76737869C5D3C]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:560)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:210)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:206)
at org.apache.solr.cloud.ShardSplitTest.splitShard(ShardSplitTest.java:532)
at org.apache.solr.cloud.ShardSplitTest.incompleteOrOverlappingCustomRangeTest(ShardSplitTest.java:151)
at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:103)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:869)
at sun.reflect.GeneratedMethodAccessor41.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:483)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:798)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:458)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:365)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:150)
at java.net.SocketInputStream.read(SocketInputStream.java:121)
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:448)
... 45 more
Build Log:
[...truncated 11554 lines...]
[junit4] Suite: org.apache.solr.cloud.ShardSplitTest
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/init-core-data-001
[junit4] 2> 2503963 T5080 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /qfv/
[junit4] 2> 2503974 T5080 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> 2503977 T5080 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2503979 T5081 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 2504085 T5080 oasc.ZkTestServer.run start zk server on port:50237
[junit4] 2> 2504093 T5080 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2504100 T5087 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@24dde8ab name:ZooKeeperConnection Watcher:127.0.0.1:50237 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2504101 T5080 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2504101 T5080 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 2504122 T5080 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2504126 T5089 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@49d0285e name:ZooKeeperConnection Watcher:127.0.0.1:50237/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2504127 T5080 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2504127 T5080 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 2504143 T5080 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 2504149 T5080 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 2504153 T5080 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 2504158 T5080 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> 2504159 T5080 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 2504167 T5080 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> 2504168 T5080 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 2504180 T5080 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> 2504181 T5080 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 2504188 T5080 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> 2504190 T5080 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 2504196 T5080 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> 2504198 T5080 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 2504203 T5080 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> 2504205 T5080 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 2504211 T5080 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> 2504212 T5080 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 2504217 T5080 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> 2504218 T5080 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 2504227 T5080 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> 2504237 T5080 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 2504252 T5080 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> 2504253 T5080 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 2504260 T5080 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> 2504260 T5080 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 2506490 T5080 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2506514 T5080 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50240
[junit4] 2> 2506514 T5080 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2506515 T5080 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2506515 T5080 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-002
[junit4] 2> 2506515 T5080 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-002/'
[junit4] 2> 2506568 T5080 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-002/solr.xml
[junit4] 2> 2506588 T5080 oasc.CoreContainer.<init> New CoreContainer 681042615
[junit4] 2> 2506588 T5080 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-002/]
[junit4] 2> 2506589 T5080 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2506589 T5080 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2506590 T5080 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2506592 T5080 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2506592 T5080 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2506593 T5080 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2506593 T5080 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2506593 T5080 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2506594 T5080 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2506594 T5080 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 2506595 T5080 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2506595 T5080 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2506595 T5080 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2506596 T5080 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50237/solr
[junit4] 2> 2506596 T5080 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2506597 T5080 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2506603 T5100 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3b7b121d name:ZooKeeperConnection Watcher:127.0.0.1:50237 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2506605 T5080 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2506610 T5080 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2506615 T5102 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@63a7dfe5 name:ZooKeeperConnection Watcher:127.0.0.1:50237/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2506615 T5080 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2506619 T5080 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 2506628 T5080 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 2506640 T5080 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 2506649 T5080 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 2506659 T5080 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 2506671 T5080 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 2506676 T5080 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50240_qfv
[junit4] 2> 2506678 T5080 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50240_qfv
[junit4] 2> 2506688 T5080 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 2506695 T5080 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 2506704 T5080 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 2506710 T5080 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:50240_qfv
[junit4] 2> 2506711 T5080 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 2506717 T5080 oasc.Overseer.start Overseer (id=92341584841146371-127.0.0.1:50240_qfv-n_0000000000) starting
[junit4] 2> 2506726 T5080 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 2506759 T5080 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
[junit4] 2> 2506761 T5104 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 2506765 T5103 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 2506767 T5080 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 2506775 T5080 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 2506782 T5080 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2506796 T5106 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
[junit4] 2> 2506796 T5106 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2506799 T5106 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2506799 T5107 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2506808 T5103 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:50240/qfv",
[junit4] 2> "node_name":"127.0.0.1:50240_qfv",
[junit4] 2> "numShards":"1",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "operation":"state"}
[junit4] 2> 2506809 T5103 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 2506809 T5103 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2506817 T5107 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> 2507800 T5106 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 2507801 T5106 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 2507802 T5106 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2507802 T5106 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 2507806 T5106 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2507806 T5106 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-002/collection1/'
[junit4] 2> 2507807 T5106 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-002/collection1/lib/.svn/' to classloader
[junit4] 2> 2507808 T5106 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-002/collection1/lib/classes/' to classloader
[junit4] 2> 2507808 T5106 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-002/collection1/lib/README' to classloader
[junit4] 2> 2507877 T5106 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0
[junit4] 2> 2507915 T5106 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2507920 T5106 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2507929 T5106 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2508064 T5106 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2508067 T5106 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2508069 T5106 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2508076 T5106 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2508153 T5106 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 2508153 T5106 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2508154 T5106 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-002/collection1/, dataDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-001/control/data/
[junit4] 2> 2508154 T5106 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4e3dce67
[junit4] 2> 2508155 T5106 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-001/control/data
[junit4] 2> 2508155 T5106 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-001/control/data/index/
[junit4] 2> 2508155 T5106 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-001/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 2508157 T5106 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-001/control/data/index
[junit4] 2> 2508157 T5106 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1453859884, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 2508159 T5106 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@85e1bef lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@20e19757),segFN=segments_1,generation=1}
[junit4] 2> 2508159 T5106 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2508165 T5106 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2508166 T5106 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2508166 T5106 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2508167 T5106 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2508167 T5106 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2508168 T5106 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2508168 T5106 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2508169 T5106 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2508169 T5106 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2508169 T5106 oasc.RequestHandlers.initHandlersFromConfig created /update: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2508170 T5106 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2508170 T5106 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2508170 T5106 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2508171 T5106 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2508171 T5106 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2508171 T5106 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2508172 T5106 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2508172 T5106 oasc.RequestHandlers.initHandlersFromConfig WARN Multiple requestHandler registered to the same name: /update ignoring: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2508173 T5106 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2508173 T5106 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2508174 T5106 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 2508174 T5106 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 2508184 T5106 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2508186 T5106 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2508187 T5106 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2508189 T5106 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2508190 T5106 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2508195 T5106 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2508196 T5106 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2508196 T5106 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=29, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=31.06640625, floorSegmentMB=0.8251953125, forceMergeDeletesPctAllowed=11.93119869288385, segmentsPerTier=45.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8074584401928482
[junit4] 2> 2508197 T5106 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@85e1bef lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@20e19757),segFN=segments_1,generation=1}
[junit4] 2> 2508197 T5106 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2508197 T5106 oass.SolrIndexSearcher.<init> Opening Searcher@3d4111e3[collection1] main
[junit4] 2> 2508198 T5106 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 2508199 T5106 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2508200 T5106 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 2508200 T5106 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2508201 T5106 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 2508201 T5106 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2508203 T5106 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 2508203 T5106 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2508205 T5106 oascc.SolrZkClient.makePath makePath: /configs/conf1/_rest_managed.json
[junit4] 2> 2508211 T5106 oasr.ManagedResourceStorage$ZooKeeperStorageIO$1.close Wrote 38 bytes to new znode /configs/conf1/_rest_managed.json
[junit4] 2> 2508211 T5106 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2508211 T5106 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 2508218 T5108 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3d4111e3[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 2508220 T5106 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2508223 T5111 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50240/qfv collection:control_collection shard:shard1
[junit4] 2> 2508224 T5080 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 2508225 T5080 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2508227 T5111 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 2508229 T5080 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2508233 T5113 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3409014e name:ZooKeeperConnection Watcher:127.0.0.1:50237/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2508234 T5080 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2508236 T5080 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2508242 T5080 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 2508253 T5111 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 2508258 T5111 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 2508258 T5111 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1911 name=collection1 org.apache.solr.core.SolrCore@720332ba url=http://127.0.0.1:50240/qfv/collection1 node=127.0.0.1:50240_qfv C1911_STATE=coll:control_collection core:collection1 props:{core=collection1, base_url=http://127.0.0.1:50240/qfv, node_name=127.0.0.1:50240_qfv, state=down}
[junit4] 2> 2508259 T5111 C1911 P50240 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50240/qfv/collection1/
[junit4] 2> 2508259 T5111 C1911 P50240 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 2508259 T5111 C1911 P50240 oasc.SyncStrategy.syncToMe http://127.0.0.1:50240/qfv/collection1/ has no replicas
[junit4] 2> 2508260 T5111 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50240/qfv/collection1/ shard1
[junit4] 2> 2508260 T5111 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 2508258 T5107 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2508307 T5107 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2508310 T5114 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> 2508314 T5107 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> 2508354 T5111 oasc.ZkController.register We are http://127.0.0.1:50240/qfv/collection1/ and leader is http://127.0.0.1:50240/qfv/collection1/
[junit4] 2> 2508354 T5111 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50240/qfv
[junit4] 2> 2508354 T5111 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 2508355 T5111 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
[junit4] 2> 2508355 T5111 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2508358 T5107 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2508365 T5103 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:50240/qfv",
[junit4] 2> "node_name":"127.0.0.1:50240_qfv",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "operation":"state"}
[junit4] 2> 2508475 T5114 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> 2508475 T5107 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> 2510212 T5080 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 2510214 T5080 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2510221 T5080 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50244
[junit4] 2> 2510223 T5080 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2510224 T5080 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2510224 T5080 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-003
[junit4] 2> 2510224 T5080 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-003/'
[junit4] 2> 2510265 T5080 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-003/solr.xml
[junit4] 2> 2510290 T5080 oasc.CoreContainer.<init> New CoreContainer 1774428814
[junit4] 2> 2510291 T5080 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-003/]
[junit4] 2> 2510293 T5080 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2510295 T5080 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2510295 T5080 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2510297 T5080 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2510297 T5080 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2510297 T5080 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2510298 T5080 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2510299 T5080 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2510299 T5080 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2510300 T5080 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 2510301 T5080 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2510302 T5080 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2510302 T5080 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2510303 T5080 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50237/solr
[junit4] 2> 2510303 T5080 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2510306 T5080 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2510310 T5125 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7f3279f8 name:ZooKeeperConnection Watcher:127.0.0.1:50237 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2510312 T5080 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2510316 T5080 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2510321 T5127 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@523136c5 name:ZooKeeperConnection Watcher:127.0.0.1:50237/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2510321 T5080 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2510344 T5080 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2511361 T5080 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50244_qfv
[junit4] 2> 2511364 T5080 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50244_qfv
[junit4] 2> 2511382 T5080 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 2511396 T5129 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 2511397 T5129 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2511400 T5129 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2511401 T5107 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2511411 T5103 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:50244/qfv",
[junit4] 2> "node_name":"127.0.0.1:50244_qfv",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"}
[junit4] 2> 2511411 T5103 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 2511411 T5103 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 2511419 T5128 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> 2511421 T5107 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> 2511422 T5114 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> 2512402 T5129 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 2512403 T5129 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 2512405 T5129 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2512405 T5129 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2512409 T5129 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2512409 T5129 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-003/collection1/'
[junit4] 2> 2512411 T5129 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-003/collection1/lib/.svn/' to classloader
[junit4] 2> 2512412 T5129 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-003/collection1/lib/classes/' to classloader
[junit4] 2> 2512413 T5129 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-003/collection1/lib/README' to classloader
[junit4] 2> 2512487 T5129 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0
[junit4] 2> 2512503 T5129 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2512508 T5129 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2512515 T5129 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2512669 T5129 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2512671 T5129 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2512672 T5129 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2512679 T5129 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2512747 T5129 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 2512747 T5129 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2512748 T5129 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-003/collection1/, dataDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-001/jetty1/
[junit4] 2> 2512748 T5129 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4e3dce67
[junit4] 2> 2512749 T5129 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-001/jetty1
[junit4] 2> 2512749 T5129 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-001/jetty1/index/
[junit4] 2> 2512749 T5129 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-001/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 2512750 T5129 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-001/jetty1/index
[junit4] 2> 2512751 T5129 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1453859884, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 2512752 T5129 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@27411567 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@659a10fe),segFN=segments_1,generation=1}
[junit4] 2> 2512753 T5129 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2512757 T5129 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2512758 T5129 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2512758 T5129 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2512759 T5129 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2512759 T5129 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2512760 T5129 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2512762 T5129 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2512762 T5129 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2512762 T5129 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2512763 T5129 oasc.RequestHandlers.initHandlersFromConfig created /update: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2512763 T5129 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2512764 T5129 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2512764 T5129 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2512765 T5129 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2512765 T5129 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2512766 T5129 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2512767 T5129 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2512767 T5129 oasc.RequestHandlers.initHandlersFromConfig WARN Multiple requestHandler registered to the same name: /update ignoring: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2512767 T5129 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2512768 T5129 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2512768 T5129 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 2512769 T5129 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 2512776 T5129 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2512778 T5129 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2512782 T5129 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2512785 T5129 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2512786 T5129 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2512791 T5129 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2512791 T5129 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2512792 T5129 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=29, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=31.06640625, floorSegmentMB=0.8251953125, forceMergeDeletesPctAllowed=11.93119869288385, segmentsPerTier=45.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8074584401928482
[junit4] 2> 2512793 T5129 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@27411567 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@659a10fe),segFN=segments_1,generation=1}
[junit4] 2> 2512794 T5129 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2512794 T5129 oass.SolrIndexSearcher.<init> Opening Searcher@10a711e2[collection1] main
[junit4] 2> 2512794 T5129 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2512798 T5129 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2512798 T5129 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 2512800 T5129 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2512800 T5129 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 2512801 T5129 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2512805 T5129 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json
[junit4] 2> 2512805 T5129 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2512806 T5129 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed
[junit4] 2> 2512806 T5129 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 2512810 T5130 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@10a711e2[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 2512814 T5129 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2512816 T5133 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50244/qfv collection:collection1 shard:shard2
[junit4] 2> 2512818 T5080 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 2512819 T5080 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2512819 T5133 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 2512846 T5133 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 2512852 T5107 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2512856 T5133 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 2512857 T5133 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1912 name=collection1 org.apache.solr.core.SolrCore@1ee822de url=http://127.0.0.1:50244/qfv/collection1 node=127.0.0.1:50244_qfv C1912_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=http://127.0.0.1:50244/qfv, node_name=127.0.0.1:50244_qfv, state=down}
[junit4] 2> 2512857 T5133 C1912 P50244 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50244/qfv/collection1/
[junit4] 2> 2512857 T5133 C1912 P50244 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 2512858 T5133 C1912 P50244 oasc.SyncStrategy.syncToMe http://127.0.0.1:50244/qfv/collection1/ has no replicas
[junit4] 2> 2512858 T5133 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50244/qfv/collection1/ shard2
[junit4] 2> 2512859 T5133 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 2512889 T5107 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2512996 T5114 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> 2512997 T5128 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> 2512998 T5107 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> 2513043 T5133 oasc.ZkController.register We are http://127.0.0.1:50244/qfv/collection1/ and leader is http://127.0.0.1:50244/qfv/collection1/
[junit4] 2> 2513043 T5133 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50244/qfv
[junit4] 2> 2513043 T5133 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 2513043 T5133 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 2513044 T5133 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2513047 T5107 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2513055 T5103 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:50244/qfv",
[junit4] 2> "node_name":"127.0.0.1:50244_qfv",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"}
[junit4] 2> 2513164 T5128 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> 2513165 T5107 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> 2513169 T5114 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> 2514832 T5080 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 2514833 T5080 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2514841 T5080 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50247
[junit4] 2> 2514845 T5080 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2514845 T5080 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2514845 T5080 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-004
[junit4] 2> 2514846 T5080 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-004/'
[junit4] 2> 2514902 T5080 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-004/solr.xml
[junit4] 2> 2514925 T5080 oasc.CoreContainer.<init> New CoreContainer 705697612
[junit4] 2> 2514926 T5080 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-004/]
[junit4] 2> 2514927 T5080 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2514927 T5080 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2514928 T5080 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2514929 T5080 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2514930 T5080 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2514931 T5080 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2514932 T5080 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2514932 T5080 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2514933 T5080 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2514934 T5080 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 2514934 T5080 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2514935 T5080 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2514936 T5080 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2514936 T5080 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50237/solr
[junit4] 2> 2514937 T5080 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2514939 T5080 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2514944 T5144 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@78da77d0 name:ZooKeeperConnection Watcher:127.0.0.1:50237 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2514945 T5080 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2514951 T5080 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2514955 T5146 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6392688b name:ZooKeeperConnection Watcher:127.0.0.1:50237/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2514956 T5080 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2514988 T5080 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2516002 T5080 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50247_qfv
[junit4] 2> 2516004 T5080 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50247_qfv
[junit4] 2> 2516020 T5080 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 2516058 T5148 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 2516059 T5148 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2516062 T5107 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2516062 T5148 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2516068 T5103 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:50247/qfv",
[junit4] 2> "node_name":"127.0.0.1:50247_qfv",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"}
[junit4] 2> 2516069 T5103 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 2516069 T5103 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 2516079 T5107 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> 2516079 T5114 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> 2516080 T5147 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> 2516079 T5128 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> 2517064 T5148 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 2517065 T5148 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 2517067 T5148 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2517067 T5148 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2517070 T5148 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2517071 T5148 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-004/collection1/'
[junit4] 2> 2517073 T5148 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-004/collection1/lib/.svn/' to classloader
[junit4] 2> 2517073 T5148 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-004/collection1/lib/classes/' to classloader
[junit4] 2> 2517074 T5148 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-004/collection1/lib/README' to classloader
[junit4] 2> 2517119 T5148 oasc.SolrConfig.<init> Using Lucene MatchVersion: 5.0.0
[junit4] 2> 2517134 T5148 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2517137 T5148 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2517142 T5148 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2517282 T5148 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2517284 T5148 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2517285 T5148 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2517291 T5148 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2517361 T5148 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 2517361 T5148 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 2517362 T5148 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-004/collection1/, dataDir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-001/jetty2/
[junit4] 2> 2517362 T5148 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4e3dce67
[junit4] 2> 2517364 T5148 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-001/jetty2
[junit4] 2> 2517364 T5148 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-001/jetty2/index/
[junit4] 2> 2517364 T5148 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-001/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 2517367 T5148 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-001/jetty2/index
[junit4] 2> 2517368 T5148 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1453859884, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 2517369 T5148 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@3c42ec0f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2ab479cb),segFN=segments_1,generation=1}
[junit4] 2> 2517369 T5148 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2517375 T5148 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2517376 T5148 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2517377 T5148 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2517377 T5148 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2517377 T5148 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2517378 T5148 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2517379 T5148 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2517380 T5148 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2517380 T5148 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2517382 T5148 oasc.RequestHandlers.initHandlersFromConfig created /update: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2517383 T5148 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2517384 T5148 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2517384 T5148 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2517385 T5148 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2517386 T5148 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2517386 T5148 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2517386 T5148 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2517387 T5148 oasc.RequestHandlers.initHandlersFromConfig WARN Multiple requestHandler registered to the same name: /update ignoring: org.apache.solr.handler.UpdateRequestHandler
[junit4] 2> 2517387 T5148 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2517388 T5148 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2517388 T5148 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 2517389 T5148 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 2517398 T5148 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2517400 T5148 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2517401 T5148 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2517404 T5148 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2517406 T5148 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2517411 T5148 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2517411 T5148 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2517412 T5148 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=29, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=31.06640625, floorSegmentMB=0.8251953125, forceMergeDeletesPctAllowed=11.93119869288385, segmentsPerTier=45.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8074584401928482
[junit4] 2> 2517412 T5148 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@3c42ec0f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@2ab479cb),segFN=segments_1,generation=1}
[junit4] 2> 2517413 T5148 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2517413 T5148 oass.SolrIndexSearcher.<init> Opening Searcher@386ac8f7[collection1] main
[junit4] 2> 2517413 T5148 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2517417 T5148 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 2517417 T5148 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 2517419 T5148 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 2517419 T5148 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 2517420 T5148 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2517424 T5148 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json
[junit4] 2> 2517425 T5148 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 2517425 T5148 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed
[junit4] 2> 2517425 T5148 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 2517432 T5149 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@386ac8f7[collection1] main{UninvertingDirectoryReader()}
[junit4] 2> 2517436 T5148 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2517439 T5152 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50247/qfv collection:collection1 shard:shard1
[junit4] 2> 2517440 T5080 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 2517440 T5080 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2517442 T5152 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2517458 T5152 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 2517462 T5107 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2517464 T5152 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 2517465 T5152 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C1913 name=collection1 org.apache.solr.core.SolrCore@3666af3e url=http://127.0.0.1:50247/qfv/collection1 node=127.0.0.1:50247_qfv C1913_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=http://127.0.0.1:50247/qfv, node_name=127.0.0.1:50247_qfv, state=down}
[junit4] 2> 2517466 T5152 C1913 P50247 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50247/qfv/collection1/
[junit4] 2> 2517466 T5152 C1913 P50247 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 2517466 T5152 C1913 P50247 oasc.SyncStrategy.syncToMe http://127.0.0.1:50247/qfv/collection1/ has no replicas
[junit4] 2> 2517467 T5152 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50247/qfv/collection1/ shard1
[junit4] 2> 2517467 T5152 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2517497 T5107 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2517604 T5147 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> 2517605 T5128 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> 2517606 T5107 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> 2517610 T5114 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> 2517644 T5152 oasc.ZkController.register We are http://127.0.0.1:50247/qfv/collection1/ and leader is http://127.0.0.1:50247/qfv/collection1/
[junit4] 2> 2517647 T5152 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50247/qfv
[junit4] 2> 2517647 T5152 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 2517647 T5152 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 2517647 T5152 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2517660 T5107 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2517666 T5103 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:50247/qfv",
[junit4] 2> "node_name":"127.0.0.1:50247_qfv",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"active",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"}
[junit4] 2> 2517778 T5147 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> 2517781 T5128 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> 2517790 T5114 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> 2517794 T5107 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> 2519555 T5080 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 2519556 T5080 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2519562 T5080 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50250
[junit4] 2> 2519564 T5080 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2519564 T5080 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2519565 T5080 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-005
[junit4] 2> 2519566 T5080 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-005/'
[junit4] 2> 2519614 T5080 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-005/solr.xml
[junit4] 2> 2519659 T5080 oasc.CoreContainer.<init> New CoreContainer 1827535008
[junit4] 2> 2519660 T5080 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001/tempDir-005/]
[junit4] 2> 2519661 T5080 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 2519661 T5080 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 2519662 T5080 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2519663 T5080 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2519663 T5080 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2519664 T5080 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2519664 T5080 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2519665 T5080 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2519665 T5080 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2519666 T5080 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
[junit4] 2> 2519667 T5080 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 2519667 T5080 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 2519668 T5080 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 2519669 T5080 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50237/solr
[junit4] 2> 2519669 T5080 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2519671 T5080 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2519675 T5163 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17b34cd9 name:ZooKeeperConnection Watcher:127.0.0.1:50237 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2519676 T5080 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2519681 T5080 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2519685 T5165 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@59a14e8a name:ZooKeeperConnection Watcher:127.0.0.1:50237/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2519685 T5080 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2519706 T5080 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2520718 T5080 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50250_qfv
[junit4] 2> 2520721 T5080 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50250_qfv
[junit4] 2> 2520736 T5080 oasc.Overseer.close Overseer (id=null) closing
[junit4] 2> 2520750 T5167 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 2520751 T5167 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2520753 T5167 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2520753 T5107 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 2520761 T5103 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "base_url":"http://127.0.0.1:50250/qfv",
[junit4] 2> "node_name":"127.0.0.1:50250_qfv",
[junit4] 2> "numShards":"2",
[junit4] 2> "state":"down",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "operation":"state"}
[junit4] 2> 2520761 T5103 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 2520762 T5103 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 2520770 T5147 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 2520771 T5107 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 2520771 T5166 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, ha
[...truncated too long message...]
unit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:206)
[junit4] > at org.apache.solr.cloud.ShardSplitTest.splitShard(ShardSplitTest.java:532)
[junit4] > at org.apache.solr.cloud.ShardSplitTest.incompleteOrOverlappingCustomRangeTest(ShardSplitTest.java:151)
[junit4] > at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:103)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:869)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] > Caused by: java.net.SocketTimeoutException: Read timed out
[junit4] > at java.net.SocketInputStream.socketRead0(Native Method)
[junit4] > at java.net.SocketInputStream.read(SocketInputStream.java:150)
[junit4] > at java.net.SocketInputStream.read(SocketInputStream.java:121)
[junit4] > at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:160)
[junit4] > at org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:84)
[junit4] > at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:273)
[junit4] > at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140)
[junit4] > at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)
[junit4] > at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:260)
[junit4] > at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:283)
[junit4] > at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:251)
[junit4] > at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:197)
[junit4] > at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:271)
[junit4] > at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:123)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:682)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:486)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:863)
[junit4] > at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
[junit4] > at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106)
[junit4] > at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:57)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:448)
[junit4] > ... 45 more
[junit4] 2> 2863029 T5080 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./temp/solr.cloud.ShardSplitTest-3311E92FF1C33D00-001
[junit4] 2> 359071 T5079 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=CheapBastard, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=hi, timezone=Pacific/Pago_Pago
[junit4] 2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.8.0_20 (64-bit)/cpus=2,threads=1,free=297447640,total=488636416
[junit4] 2> NOTE: All tests run in this JVM: [TestFieldResource, MergeStrategyTest, AnalysisAfterCoreReloadTest, QueryResultKeyTest, RankQueryTest, HttpPartitionTest, TestTolerantSearch, TestDynamicFieldCollectionResource, TestSuggestSpellingConverter, TestSolrQueryParserDefaultOperatorResource, SolrIndexSplitterTest, FieldFacetTest, TestJmxMonitoredMap, ExpressionTest, EnumFieldTest, UpdateRequestProcessorFactoryTest, CoreContainerCoreInitFailuresTest, TestSurroundQueryParser, TestBinaryField, TestOmitPositions, TestHighFrequencyDictionaryFactory, TestFaceting, CacheHeaderTest, TestFastWriter, TestRestManager, TestUtils, TestArbitraryIndexDir, ModifyConfFileTest, TestRandomMergePolicy, TestFastLRUCache, TestBinaryResponseWriter, NoCacheHeaderTest, SystemInfoHandlerTest, ZkCLITest, TestIndexingPerformance, TestCollapseQParserPlugin, PathHierarchyTokenizerFactoryTest, TestSolr4Spatial, SolrCmdDistributorTest, TestZkChroot, FieldAnalysisRequestHandlerTest, SolrXmlInZkTest, NumericFieldsTest, TestStressReorder, QueryEqualityTest, TestStressRecovery, TestReversedWildcardFilterFactory, AssignTest, TestDFRSimilarityFactory, SoftAutoCommitTest, SuggesterWFSTTest, StatelessScriptUpdateProcessorFactoryTest, MoreLikeThisHandlerTest, DateMathParserTest, ExternalFileFieldSortTest, DocValuesMissingTest, CollectionsAPIAsyncDistributedZkTest, CursorPagingTest, TestExpandComponent, TestManagedSynonymFilterFactory, TestCollectionAPI, TestStressLucene, QueryParsingTest, DocValuesMultiTest, DistributedQueryElevationComponentTest, TestQueryTypes, SchemaVersionSpecificBehaviorTest, HdfsWriteToMultipleCollectionsTest, TestPerFieldSimilarity, CoreAdminRequestStatusTest, DirectUpdateHandlerOptimizeTest, SuggesterTest, PrimitiveFieldTypeTest, CursorMarkTest, TestMergePolicyConfig, DistributedExpandComponentTest, AutoCommitTest, TestRecoveryHdfs, TestCoreDiscovery, TestDocSet, BadComponentTest, TestSchemaVersionResource, DistanceFunctionTest, MBeansHandlerTest, ReturnFieldsTest, TestMaxScoreQueryParser, SuggesterFSTTest, SpellingQueryConverterTest, WordBreakSolrSpellCheckerTest, TestLuceneMatchVersion, MultiThreadedOCPTest, TestNonNRTOpen, IndexSchemaTest, TestValueSourceCache, HdfsUnloadDistributedZkTest, TestGroupingSearch, TermsComponentTest, TestCharFilters, FunctionTest, TestCSVResponseWriter, JsonLoaderTest, TestCursorMarkWithoutUniqueKey, AnalysisErrorHandlingTest, TestShortCircuitedRequests, DirectSolrConnectionTest, RequiredFieldsTest, TermVectorComponentTest, TestMissingGroups, LukeRequestHandlerTest, TestReRankQParserPlugin, TestFieldCollectionResource, TestShardHandlerFactory, DateFieldTest, TestNonDefinedSimilarityFactory, SpellCheckComponentTest, TriLevelCompositeIdRoutingTest, DebugComponentTest, TestSolrXmlPersistence, TestFuzzyAnalyzedSuggestions, JSONWriterTest, TestXIncludeConfig, TestConfig, ZkNodePropsTest, TestPivotHelperCode, TermVectorComponentDistributedTest, UUIDUpdateProcessorFallbackTest, DistributedDebugComponentTest, DistributedSpellCheckComponentTest, ResourceLoaderTest, TestNoOpRegenerator, MinimalSchemaTest, TestAddFieldRealTimeGet, ResponseLogComponentTest, TestOrdValues, BlockCacheTest, TestIBSimilarityFactory, TestAnalyzedSuggestions, XsltUpdateRequestHandlerTest, TestSolrCoreProperties, SimplePostToolTest, OverseerStatusTest, PreAnalyzedUpdateProcessorTest, OutputWriterTest, LeaderElectionTest, NoFacetTest, TestDocBasedVersionConstraints, TestUpdate, TestQuerySenderNoQuery, TestFreeTextSuggestions, TestDefaultSimilarityFactory, SimpleFacetsTest, TestCoreContainer, TestLMJelinekMercerSimilarityFactory, PingRequestHandlerTest, TestSolrQueryParser, TestReplicationHandlerBackup, DeleteShardTest, ChangedSchemaMergeTest, TestChildDocTransformer, TestRecovery, TestDefaultSearchFieldResource, TestFastOutputStream, HardAutoCommitTest, SyncSliceTest, TestReloadAndDeleteDocs, TestRandomFaceting, TestIntervalFaceting, SuggestComponentTest, SharedFSAutoReplicaFailoverUtilsTest, LoggingHandlerTest, PolyFieldTest, ResponseHeaderTest, SolrIndexConfigTest, RecoveryZkTest, DistribDocExpirationUpdateProcessorTest, TestSolrIndexConfig, TestMiniSolrCloudCluster, TestCloudSchemaless, TestOverriddenPrefixQueryForCustomFieldType, FileBasedSpellCheckerTest, DirectSolrSpellCheckerTest, ShowFileRequestHandlerTest, TestJoin, TestPostingsSolrHighlighter, CoreMergeIndexesAdminHandlerTest, PeerSyncTest, HdfsChaosMonkeySafeLeaderTest, TestRequestStatusCollectionAPI, AlternateDirectoryTest, TestWriterPerf, TestSolrDeletionPolicy1, TestStressUserVersions, SolrCoreCheckLockOnStartupTest, TestQuerySenderListener, TestSerializedLuceneMatchVersion, SOLR749Test, TestDistributedGrouping, TestDistributedMissingSort, TestLRUCache, TestFunctionQuery, AbstractAnalyticsStatsTest, TestDistributedSearch, TestSweetSpotSimilarityFactory, RangeFacetTest, SolrCoreTest, RequestHandlersTest, ShardSplitTest]
[junit4] Completed in 359.40s, 1 test, 1 error <<< FAILURES!
[...truncated 690 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:485: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:465: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:48: 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:494: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1342: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:957: There were test failures: 430 suites, 1784 tests, 1 error, 47 ignored (20 assumptions)
Total time: 152 minutes 20 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any