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 2013/10/07 11:49:54 UTC
[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.7.0) - Build # 892 -
Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/892/
Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseParallelGC
2 tests failed.
REGRESSION: org.apache.solr.cloud.AliasIntegrationTest.testDistribSearch
Error Message:
deletealias the collection time out:60s
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: deletealias the collection time out:60s
at __randomizedtesting.SeedInfo.seed([D905D395D68DCC8D:58E35D8DA1D2ACB1]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:463)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
at org.apache.solr.cloud.AliasIntegrationTest.deleteAlias(AliasIntegrationTest.java:254)
at org.apache.solr.cloud.AliasIntegrationTest.doTest(AliasIntegrationTest.java:227)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
REGRESSION: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.testDistribSearch
Error Message:
No live SolrServers available to handle this request:[http://127.0.0.1:50216/collection1, http://127.0.0.1:50206/collection1, http://127.0.0.1:50209/collection1, http://127.0.0.1:50242/collection1, http://127.0.0.1:50237/collection1, http://127.0.0.1:50257/collection1, http://127.0.0.1:50230/collection1, http://127.0.0.1:50247/collection1, http://127.0.0.1:50203/collection1, http://127.0.0.1:50252/collection1, http://127.0.0.1:50212/collection1, http://127.0.0.1:50223/collection1]
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:50216/collection1, http://127.0.0.1:50206/collection1, http://127.0.0.1:50209/collection1, http://127.0.0.1:50242/collection1, http://127.0.0.1:50237/collection1, http://127.0.0.1:50257/collection1, http://127.0.0.1:50230/collection1, http://127.0.0.1:50247/collection1, http://127.0.0.1:50203/collection1, http://127.0.0.1:50252/collection1, http://127.0.0.1:50212/collection1, http://127.0.0.1:50223/collection1]
at __randomizedtesting.SeedInfo.seed([D905D395D68DCC8D:58E35D8DA1D2ACB1]:0)
at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:337)
at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:623)
at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:90)
at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1139)
at org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.doTest(ChaosMonkeySafeLeaderTest.java:137)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Caused by: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:50230/collection1
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:474)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:268)
... 46 more
Caused by: java.net.SocketException: Invalid argument
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.read(SocketInputStream.java:152)
at java.net.SocketInputStream.read(SocketInputStream.java:122)
at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:166)
at org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:90)
at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:281)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:92)
at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:61)
at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:254)
at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:289)
at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:252)
at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:191)
at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:300)
at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:127)
at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:715)
at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:520)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:366)
... 48 more
Build Log:
[...truncated 9886 lines...]
[junit4] Suite: org.apache.solr.cloud.AliasIntegrationTest
[junit4] 2> 617255 T1232 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 617264 T1232 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-AliasIntegrationTest-1381136410589
[junit4] 2> 617266 T1232 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 617267 T1233 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 617369 T1232 oasc.ZkTestServer.run start zk server on port:49544
[junit4] 2> 617371 T1232 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 617380 T1239 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@136f6ed1 name:ZooKeeperConnection Watcher:127.0.0.1:49544 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 617381 T1232 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 617382 T1232 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 617400 T1232 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 617407 T1241 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4f5f1fd4 name:ZooKeeperConnection Watcher:127.0.0.1:49544/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 617409 T1232 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 617411 T1232 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 617422 T1232 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 617431 T1232 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 617440 T1232 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 617449 T1232 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 617451 T1232 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 617466 T1232 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 617467 T1232 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 617477 T1232 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 617478 T1232 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 617488 T1232 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 617489 T1232 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 617498 T1232 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 617500 T1232 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 617511 T1232 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 617511 T1232 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 617521 T1232 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 617522 T1232 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 617532 T1232 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 617533 T1232 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 617543 T1232 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 617544 T1232 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 617553 T1232 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 617555 T1232 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 618079 T1232 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 618089 T1232 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49547
[junit4] 2> 618090 T1232 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 618091 T1232 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 618091 T1232 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.AliasIntegrationTest-controljetty-1381136410891
[junit4] 2> 618092 T1232 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.AliasIntegrationTest-controljetty-1381136410891/'
[junit4] 2> 618131 T1232 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-controljetty-1381136410891/solr.xml
[junit4] 2> 618229 T1232 oasc.CoreContainer.<init> New CoreContainer 1882264500
[junit4] 2> 618229 T1232 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.AliasIntegrationTest-controljetty-1381136410891/]
[junit4] 2> 618232 T1232 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 618232 T1232 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 618233 T1232 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 618234 T1232 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 618234 T1232 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 618235 T1232 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 618235 T1232 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 618236 T1232 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 618236 T1232 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 618237 T1232 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 618242 T1232 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 618243 T1232 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 618244 T1232 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49544/solr
[junit4] 2> 618245 T1232 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 618247 T1232 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 618252 T1252 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1eb29885 name:ZooKeeperConnection Watcher:127.0.0.1:49544 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 618253 T1232 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 618259 T1232 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 618262 T1232 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 618268 T1254 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4f501c9a name:ZooKeeperConnection Watcher:127.0.0.1:49544/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 618268 T1232 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 618273 T1232 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 618285 T1232 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 618296 T1232 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 618302 T1232 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49547_
[junit4] 2> 618305 T1232 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49547_
[junit4] 2> 618317 T1232 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 618331 T1232 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 618337 T1232 oasc.Overseer.start Overseer (id=90514155804950531-127.0.0.1:49547_-n_0000000000) starting
[junit4] 2> 618347 T1232 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 618358 T1256 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 618359 T1232 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 618367 T1232 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 618372 T1232 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 618381 T1255 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 618392 T1257 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 618392 T1257 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 618395 T1257 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 619900 T1255 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 619903 T1255 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:49547",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49547_",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 619903 T1255 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 619904 T1255 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 619919 T1254 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> 620407 T1257 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 620407 T1257 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.AliasIntegrationTest-controljetty-1381136410891/collection1
[junit4] 2> 620408 T1257 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 620410 T1257 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 620411 T1257 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 620414 T1257 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.AliasIntegrationTest-controljetty-1381136410891/collection1/'
[junit4] 2> 620416 T1257 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-controljetty-1381136410891/collection1/lib/classes/' to classloader
[junit4] 2> 620417 T1257 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-controljetty-1381136410891/collection1/lib/README' to classloader
[junit4] 2> 620537 T1257 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 620644 T1257 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 620648 T1257 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 620660 T1257 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 621616 T1257 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 621643 T1257 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 621654 T1257 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 621706 T1257 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 621713 T1257 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 621721 T1257 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 621724 T1257 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 621725 T1257 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 621726 T1257 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 621729 T1257 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 621729 T1257 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 621730 T1257 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 621730 T1257 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.AliasIntegrationTest-controljetty-1381136410891/collection1/, dataDir=./org.apache.solr.cloud.AliasIntegrationTest-1381136410588/control/data/
[junit4] 2> 621731 T1257 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@178fd0ca
[junit4] 2> 621732 T1257 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.AliasIntegrationTest-1381136410588/control/data
[junit4] 2> 621732 T1257 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.AliasIntegrationTest-1381136410588/control/data/index/
[junit4] 2> 621733 T1257 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.AliasIntegrationTest-1381136410588/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 621733 T1257 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.AliasIntegrationTest-1381136410588/control/data/index
[junit4] 2> 621734 T1257 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=28, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.312211925068285]
[junit4] 2> 621735 T1257 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@430b1f56 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@269de3d6),segFN=segments_1,generation=1}
[junit4] 2> 621736 T1257 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 621741 T1257 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 621742 T1257 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 621742 T1257 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 621743 T1257 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 621743 T1257 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 621743 T1257 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 621744 T1257 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 621745 T1257 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 621745 T1257 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 621746 T1257 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 621746 T1257 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 621747 T1257 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 621747 T1257 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 621748 T1257 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 621749 T1257 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 621764 T1257 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 621774 T1257 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 621774 T1257 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 621775 T1257 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=44, maxMergeAtOnceExplicit=32, maxMergedSegmentMB=59.4853515625, floorSegmentMB=0.3251953125, forceMergeDeletesPctAllowed=24.484791672314977, segmentsPerTier=26.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8582180622483458
[junit4] 2> 621776 T1257 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@430b1f56 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@269de3d6),segFN=segments_1,generation=1}
[junit4] 2> 621777 T1257 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 621777 T1257 oass.SolrIndexSearcher.<init> Opening Searcher@6e4991af main
[junit4] 2> 621783 T1258 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6e4991af main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 621786 T1257 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 621786 T1257 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49547 collection:control_collection shard:shard1
[junit4] 2> 621787 T1257 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 621791 T1257 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 621816 T1257 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 621824 T1257 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 621825 T1257 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 621825 T1257 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49547/collection1/
[junit4] 2> 621826 T1257 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 621826 T1257 oasc.SyncStrategy.syncToMe http://127.0.0.1:49547/collection1/ has no replicas
[junit4] 2> 621826 T1257 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49547/collection1/ shard1
[junit4] 2> 621827 T1257 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 622941 T1255 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 622967 T1254 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> 622984 T1257 oasc.ZkController.register We are http://127.0.0.1:49547/collection1/ and leader is http://127.0.0.1:49547/collection1/
[junit4] 2> 622985 T1257 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49547
[junit4] 2> 622985 T1257 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 622985 T1257 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 622986 T1257 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 622991 T1257 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 622996 T1232 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 622997 T1232 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 622998 T1232 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 622999 T1232 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4] 2> 623002 T1232 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 623009 T1261 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3f43308 name:ZooKeeperConnection Watcher:127.0.0.1:49544/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 623009 T1232 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 623015 T1232 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 623024 T1232 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 623577 T1232 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 623584 T1232 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49551
[junit4] 2> 623587 T1232 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 623587 T1232 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 623588 T1232 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty1-1381136416349
[junit4] 2> 623588 T1232 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty1-1381136416349/'
[junit4] 2> 623634 T1232 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty1-1381136416349/solr.xml
[junit4] 2> 623763 T1232 oasc.CoreContainer.<init> New CoreContainer 1953019774
[junit4] 2> 623764 T1232 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty1-1381136416349/]
[junit4] 2> 623767 T1232 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 623768 T1232 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 623768 T1232 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 623769 T1232 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 623769 T1232 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 623770 T1232 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 623771 T1232 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 623771 T1232 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 623772 T1232 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 623773 T1232 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 623778 T1232 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 623779 T1232 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 623780 T1232 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49544/solr
[junit4] 2> 623780 T1232 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 623782 T1232 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 623789 T1272 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4b13c655 name:ZooKeeperConnection Watcher:127.0.0.1:49544 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 623790 T1232 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 623796 T1232 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 623800 T1232 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 623806 T1274 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@349445e4 name:ZooKeeperConnection Watcher:127.0.0.1:49544/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 623806 T1232 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 623821 T1232 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 624486 T1255 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 624488 T1255 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:49547",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49547_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 624500 T1261 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> 624500 T1254 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> 624500 T1274 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> 624834 T1232 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49551_
[junit4] 2> 624837 T1232 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49551_
[junit4] 2> 624845 T1274 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 624845 T1254 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 624845 T1261 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 624866 T1275 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 624867 T1275 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 624870 T1275 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 626020 T1255 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 626022 T1255 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:49551",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49551_",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 626023 T1255 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 626024 T1255 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 626049 T1274 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> 626050 T1261 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> 626050 T1254 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> 626874 T1275 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 626875 T1275 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty1-1381136416349/collection1
[junit4] 2> 626875 T1275 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 626877 T1275 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 626877 T1275 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 626880 T1275 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty1-1381136416349/collection1/'
[junit4] 2> 626882 T1275 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-jetty1-1381136416349/collection1/lib/classes/' to classloader
[junit4] 2> 626883 T1275 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-jetty1-1381136416349/collection1/lib/README' to classloader
[junit4] 2> 626978 T1275 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 627068 T1275 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 627072 T1275 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 627090 T1275 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 628043 T1275 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 628059 T1275 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 628064 T1275 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 628107 T1275 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 628117 T1275 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 628127 T1275 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 628132 T1275 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 628134 T1275 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 628134 T1275 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 628138 T1275 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 628139 T1275 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 628139 T1275 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 628140 T1275 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty1-1381136416349/collection1/, dataDir=./org.apache.solr.cloud.AliasIntegrationTest-1381136410588/jetty1/
[junit4] 2> 628140 T1275 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@178fd0ca
[junit4] 2> 628142 T1275 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.AliasIntegrationTest-1381136410588/jetty1
[junit4] 2> 628142 T1275 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.AliasIntegrationTest-1381136410588/jetty1/index/
[junit4] 2> 628143 T1275 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.AliasIntegrationTest-1381136410588/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 628144 T1275 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.AliasIntegrationTest-1381136410588/jetty1/index
[junit4] 2> 628145 T1275 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=28, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.312211925068285]
[junit4] 2> 628147 T1275 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@e7c37d1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@e24af2d),segFN=segments_1,generation=1}
[junit4] 2> 628147 T1275 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 628156 T1275 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 628157 T1275 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 628158 T1275 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 628159 T1275 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 628159 T1275 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 628160 T1275 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 628161 T1275 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 628162 T1275 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 628162 T1275 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 628164 T1275 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 628166 T1275 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 628166 T1275 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 628167 T1275 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 628168 T1275 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 628169 T1275 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 628186 T1275 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 628194 T1275 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 628195 T1275 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 628196 T1275 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=44, maxMergeAtOnceExplicit=32, maxMergedSegmentMB=59.4853515625, floorSegmentMB=0.3251953125, forceMergeDeletesPctAllowed=24.484791672314977, segmentsPerTier=26.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8582180622483458
[junit4] 2> 628198 T1275 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@e7c37d1 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@e24af2d),segFN=segments_1,generation=1}
[junit4] 2> 628198 T1275 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 628199 T1275 oass.SolrIndexSearcher.<init> Opening Searcher@3151ee66 main
[junit4] 2> 628211 T1276 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3151ee66 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 628215 T1275 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 628216 T1275 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49551 collection:collection1 shard:shard1
[junit4] 2> 628217 T1275 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 628220 T1275 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 628244 T1275 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 628254 T1275 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 628254 T1275 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 628254 T1275 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49551/collection1/
[junit4] 2> 628255 T1275 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 628255 T1275 oasc.SyncStrategy.syncToMe http://127.0.0.1:49551/collection1/ has no replicas
[junit4] 2> 628255 T1275 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49551/collection1/ shard1
[junit4] 2> 628256 T1275 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 629075 T1255 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 629101 T1274 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> 629101 T1254 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> 629101 T1261 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> 629138 T1275 oasc.ZkController.register We are http://127.0.0.1:49551/collection1/ and leader is http://127.0.0.1:49551/collection1/
[junit4] 2> 629139 T1275 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49551
[junit4] 2> 629139 T1275 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 629139 T1275 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 629140 T1275 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 629144 T1275 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 629148 T1232 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 629149 T1232 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 629150 T1232 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 629707 T1232 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 629723 T1232 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49554
[junit4] 2> 629725 T1232 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 629727 T1232 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 629728 T1232 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty2-1381136422475
[junit4] 2> 629729 T1232 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty2-1381136422475/'
[junit4] 2> 629801 T1232 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty2-1381136422475/solr.xml
[junit4] 2> 629949 T1232 oasc.CoreContainer.<init> New CoreContainer 2002644177
[junit4] 2> 629950 T1232 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty2-1381136422475/]
[junit4] 2> 629952 T1232 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 629953 T1232 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 629953 T1232 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 629954 T1232 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 629954 T1232 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 629955 T1232 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 629955 T1232 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 629956 T1232 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 629956 T1232 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 629957 T1232 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 629964 T1232 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 629964 T1232 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 629965 T1232 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49544/solr
[junit4] 2> 629965 T1232 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 629968 T1232 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 629973 T1288 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4d52e43f name:ZooKeeperConnection Watcher:127.0.0.1:49544 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 629975 T1232 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 629982 T1232 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 629987 T1232 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 629993 T1290 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@75afbe84 name:ZooKeeperConnection Watcher:127.0.0.1:49544/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 629994 T1232 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 630015 T1232 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 630625 T1255 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 630628 T1255 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:49551",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49551_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 630643 T1274 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> 630644 T1261 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> 630643 T1290 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4] 2> 630644 T1254 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> 631031 T1232 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49554_
[junit4] 2> 631036 T1232 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49554_
[junit4] 2> 631050 T1274 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 631051 T1261 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 631051 T1254 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 631051 T1290 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 631086 T1291 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 631087 T1291 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 631091 T1291 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 632166 T1255 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 632168 T1255 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:49554",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49554_",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 632168 T1255 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 632169 T1255 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 632179 T1290 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 632179 T1274 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> 632180 T1261 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> 632180 T1254 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> 633099 T1291 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 633100 T1291 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty2-1381136422475/collection1
[junit4] 2> 633100 T1291 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 633102 T1291 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 633102 T1291 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 633105 T1291 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty2-1381136422475/collection1/'
[junit4] 2> 633108 T1291 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-jetty2-1381136422475/collection1/lib/classes/' to classloader
[junit4] 2> 633109 T1291 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.AliasIntegrationTest-jetty2-1381136422475/collection1/lib/README' to classloader
[junit4] 2> 633213 T1291 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 633306 T1291 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 633310 T1291 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 633327 T1291 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 634374 T1291 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 634391 T1291 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 634398 T1291 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 634456 T1291 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 634469 T1291 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 634482 T1291 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 634487 T1291 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 634489 T1291 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 634490 T1291 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 634495 T1291 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 634496 T1291 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 634497 T1291 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 634498 T1291 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty2-1381136422475/collection1/, dataDir=./org.apache.solr.cloud.AliasIntegrationTest-1381136410588/jetty2/
[junit4] 2> 634499 T1291 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@178fd0ca
[junit4] 2> 634501 T1291 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.AliasIntegrationTest-1381136410588/jetty2
[junit4] 2> 634502 T1291 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.AliasIntegrationTest-1381136410588/jetty2/index/
[junit4] 2> 634502 T1291 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.AliasIntegrationTest-1381136410588/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 634503 T1291 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.AliasIntegrationTest-1381136410588/jetty2/index
[junit4] 2> 634505 T1291 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=28, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.312211925068285]
[junit4] 2> 634507 T1291 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7326f808 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6f681604),segFN=segments_1,generation=1}
[junit4] 2> 634508 T1291 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 634518 T1291 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 634520 T1291 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 634520 T1291 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 634521 T1291 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 634521 T1291 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 634522 T1291 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 634523 T1291 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 634524 T1291 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 634525 T1291 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 634527 T1291 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 634529 T1291 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 634529 T1291 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 634530 T1291 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 634532 T1291 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 634534 T1291 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 634561 T1291 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 634573 T1291 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 634574 T1291 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 634576 T1291 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=44, maxMergeAtOnceExplicit=32, maxMergedSegmentMB=59.4853515625, floorSegmentMB=0.3251953125, forceMergeDeletesPctAllowed=24.484791672314977, segmentsPerTier=26.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8582180622483458
[junit4] 2> 634577 T1291 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@7326f808 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6f681604),segFN=segments_1,generation=1}
[junit4] 2> 634578 T1291 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 634580 T1291 oass.SolrIndexSearcher.<init> Opening Searcher@4c07d1 main
[junit4] 2> 634592 T1292 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4c07d1 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 634599 T1291 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 634600 T1291 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49554 collection:collection1 shard:shard1
[junit4] 2> 634601 T1291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 634617 T1291 oasc.ZkController.register We are http://127.0.0.1:49554/collection1/ and leader is http://127.0.0.1:49551/collection1/
[junit4] 2> 634618 T1291 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49554
[junit4] 2> 634618 T1291 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 634619 T1291 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C340 name=collection1 org.apache.solr.core.SolrCore@50b1d8ac url=http://127.0.0.1:49554/collection1 node=127.0.0.1:49554_ C340_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:49554, core=collection1, node_name=127.0.0.1:49554_}
[junit4] 2> 634621 T1293 C340 P49554 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 634623 T1293 C340 P49554 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 634623 T1291 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 634624 T1293 C340 P49554 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 634626 T1293 C340 P49554 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 634631 T1232 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 634632 T1232 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 634631 T1293 C340 P49554 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 634633 T1232 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 634642 T1269 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 635207 T1255 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 635211 T1255 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "base_url":"http://127.0.0.1:49554",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49554_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 635230 T1274 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> 635232 T1261 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> 635232 T1254 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> 635236 T1290 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4] 2> 635397 T1232 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 635405 T1232 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49558
[junit4] 2> 635408 T1232 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 635409 T1232 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 635410 T1232 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.AliasIntegrationTest-jetty3-1381136427960
[junit4] 2> 635411 T1232 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.AliasIntegrationTest-jetty3-1381136427960/'
[junit4] 2> 635482 T1232 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.AliasIntegrationTest-jetty3-1381136427960/solr.xml
[junit4] 2> 635646 T1269 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4] 2> 635647 T1269 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=core_node2&state=recovering&nodeName=127.0.0.1:49554_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1005
[junit4] 2> 635678 T1232 oasc.CoreContainer.<init> New CoreContainer 150419704
[junit4] 2> 635679 T1232 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.AliasIntegrationTest-jetty3-1381136427960/]
[junit4] 2> 635683 T1232 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 635685 T1232 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 635686 T1232 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 635686 T1232 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 635687 T1232 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 635688 T1232 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 635689 T1232 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 635690 T1232 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 635691 T1232 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 635692 T1232 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 635702 T1232 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 635704 T1232 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 635705 T1232 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49544/solr
[junit4] 2> 635706 T1232 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 635708 T1232 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 635715 T1305 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@73e43280 name:ZooKeeperConnection Watcher:127.0.0.1:49544 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 635717 T1232 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 635725 T1232 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 635731 T1232 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 635738 T1307 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@72136bbe name:ZooKeeperConnection Watcher:127.0.0.1:49544/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 635739 T1232 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 635757 T1232 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 636771 T1232 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49558_
[junit4] 2> 636775 T1232 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49558_
[junit4] 2> 636792 T1290 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 636793 T1254 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 636792 T1274 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 636793 T1261 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 636796 T1307 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 636830 T1308 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 636831 T1308 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 636836 T1308 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> ASYNC NEW_CORE C341 name=collection1 org.apache.solr.core.SolrCore@50b1d8ac url=http://127.0.0.1:49554/collection1 node=127.0.0.1:49554_ C341_STATE=coll:collection1 core:collection1 props:{state=recovering, base_url=http://127.0.0.1:49554, core=collection1, node_name=127.0.0.1:49554_}
[junit4] 2> 637650 T1293 C341 P49554 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:49551/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4] 2> 637651 T1293 C341 P49554 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:49554 START replicas=[http://127.0.0.1:49551/collection1/] nUpdates=100
[junit4] 2> 637652 T1293 C341 P49554 oasu.PeerSync.sync WARN no frame of reference to tell if we've missed updates
[junit4] 2> 637653 T1293 C341 P49554 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4] 2> 637654 T1293 C341 P49554 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4] 2> 637658 T1293 C341 P49554 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4] 2> 637659 T1293 C341 P49554 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4] 2> 637659 T1293 C341 P49554 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:49551/collection1/. core=collection1
[junit4] 2> 637660 T1293 C341 P49554 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> ASYNC NEW_CORE C342 name=collection1 org.apache.solr.core.SolrCore@5550cfef url=http://127.0.0.1:49551/collection1 node=127.0.0.1:49551_ C342_STATE=coll:collection1 core:collection1 props:{state=active, base_url=http://127.0.0.1:49551, core=collection1, node_name=127.0.0.1:49551_, leader=true}
[junit4] 2> 637677 T1265 C342 P49551 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=2
[junit4] 2> 637681 T1266 C342 P49551 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 637682 T1266 C342 P49551 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4] 2> 637683 T1266 C342 P49551 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 637684 T1266 C342 P49551 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 2
[junit4] 2> 637686 T1293 C341 P49554 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 637687 T1293 C341 P49554 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4] 2> 637692 T1268 C342 P49551 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 637693 T1268 C342 P49551 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=2
[junit4] 2> 637694 T1293 C341 P49554 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4] 2> 637695 T1293 C341 P49554 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4] 2> 637695 T1293 C341 P49554 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 637695 T1293 C341 P49554 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 637699 T1293 C341 P49554 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4] 2> 638277 T1255 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 638279 T1255 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:49558",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49558_",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node3"}
[junit4] 2> 638279 T1255 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 638280 T1255 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 638291 T1255 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:49554
[...truncated too long message...]
s available to handle this request:[http://127.0.0.1:50216/collection1, http://127.0.0.1:50206/collection1, http://127.0.0.1:50209/collection1, http://127.0.0.1:50242/collection1, http://127.0.0.1:50237/collection1, http://127.0.0.1:50257/collection1, http://127.0.0.1:50230/collection1, http://127.0.0.1:50247/collection1, http://127.0.0.1:50203/collection1, http://127.0.0.1:50252/collection1, http://127.0.0.1:50212/collection1, http://127.0.0.1:50223/collection1]
[junit4] > at __randomizedtesting.SeedInfo.seed([D905D395D68DCC8D:58E35D8DA1D2ACB1]:0)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:337)
[junit4] > at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:623)
[junit4] > at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:90)
[junit4] > at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
[junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1139)
[junit4] > at org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.doTest(ChaosMonkeySafeLeaderTest.java:137)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4] > Caused by: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: http://127.0.0.1:50230/collection1
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:474)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:181)
[junit4] > at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:268)
[junit4] > ... 46 more
[junit4] > Caused by: java.net.SocketException: Invalid argument
[junit4] > at java.net.SocketInputStream.socketRead0(Native Method)
[junit4] > at java.net.SocketInputStream.read(SocketInputStream.java:152)
[junit4] > at java.net.SocketInputStream.read(SocketInputStream.java:122)
[junit4] > at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:166)
[junit4] > at org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:90)
[junit4] > at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:281)
[junit4] > at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:92)
[junit4] > at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:61)
[junit4] > at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:254)
[junit4] > at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:289)
[junit4] > at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:252)
[junit4] > at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:191)
[junit4] > at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:300)
[junit4] > at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:127)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:715)
[junit4] > at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:520)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:906)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:805)
[junit4] > at org.apache.http.impl.client.AbstractHttpClient.execute(AbstractHttpClient.java:784)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:366)
[junit4] > ... 48 more
[junit4] 2> 1677361 T3607 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 120967 T3606 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4] 2> 1677763 T3840 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Lucene46: {range_facet_l=PostingsFormat(name=MockRandom), text=PostingsFormat(name=Memory doPackFST= false), _version_=PostingsFormat(name=MockRandom), rnd_b=PostingsFormat(name=FSTPulsing41), intDefault=PostingsFormat(name=MockRandom), timestamp=PostingsFormat(name=MockRandom), id=PostingsFormat(name=FSTPulsing41), a_t=PostingsFormat(name=MockRandom), range_facet_sl=PostingsFormat(name=Memory doPackFST= false), range_facet_si=FSTOrd41, other_tl1=PostingsFormat(name=MockRandom), multiDefault=FSTOrd41, a_si=FSTOrd41}, docValues:{timestamp=DocValuesFormat(name=Disk)}, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=sr_BA, timezone=MIT
[junit4] 2> NOTE: Mac OS X 10.8.4 x86_64/Oracle Corporation 1.7.0_40 (64-bit)/cpus=2,threads=3,free=206341104,total=346030080
[junit4] 2> NOTE: All tests run in this JVM: [MultiTermTest, TestFunctionQuery, TestSweetSpotSimilarityFactory, SolrXmlInZkTest, TestSchemaResource, ConvertedLegacyTest, TestSolrDeletionPolicy1, HardAutoCommitTest, BasicDistributedZkTest, TestMergePolicyConfig, TestMaxScoreQueryParser, TestRemoteStreaming, TestLRUCache, TestLFUCache, PeerSyncTest, TestShardHandlerFactory, BlockCacheTest, TestWordDelimiterFilterFactory, TestJoin, SynonymTokenizerTest, SampleTest, TestAnalyzeInfixSuggestions, IndexSchemaTest, AnalysisAfterCoreReloadTest, TestLMDirichletSimilarityFactory, CoreContainerCoreInitFailuresTest, TestSolr4Spatial, QueryElevationComponentTest, TermVectorComponentDistributedTest, TestSolrXml, TestInfoStreamLogging, HdfsUnloadDistributedZkTest, TestHashPartitioner, ShardRoutingTest, DirectUpdateHandlerOptimizeTest, StatsComponentTest, MoreLikeThisHandlerTest, TestBinaryResponseWriter, TestStressLucene, TestFaceting, InfoHandlerTest, NotRequiredUniqueKeyTest, SimpleFacetsTest, TestSolrXmlPersistor, TermVectorComponentTest, TestLMJelinekMercerSimilarityFactory, HdfsCollectionsAPIDistributedZkTest, ParsingFieldUpdateProcessorsTest, TestFastWriter, RequestHandlersTest, HdfsChaosMonkeySafeLeaderTest, TestDocSet, TestBM25SimilarityFactory, QueryEqualityTest, CoreAdminHandlerTest, TestSolrQueryParser, TestSchemaNameResource, TestConfig, FieldAnalysisRequestHandlerTest, XmlUpdateRequestHandlerTest, AliasIntegrationTest, DocValuesTest, SolrPluginUtilsTest, CircularListTest, TestFastOutputStream, SortByFunctionTest, DocValuesMissingTest, HdfsLockFactoryTest, RAMDirectoryFactoryTest, TestNoOpRegenerator, SyncSliceTest, CachingDirectoryFactoryTest, TestFastLRUCache, TestClassNameShortening, ShardSplitTest, TestGroupingSearch, BlockDirectoryTest, BasicZkTest, DeleteShardTest, TestArbitraryIndexDir, SolrInfoMBeanTest, TestCoreContainer, TestRTGBase, ScriptEngineTest, TestAnalyzedSuggestions, CurrencyFieldXmlFileTest, LukeRequestHandlerTest, TestFieldTypeResource, HdfsDirectoryTest, TestStressRecovery, ChaosMonkeyNothingIsSafeTest, OpenExchangeRatesOrgProviderTest, TestPartialUpdateDeduplication, TestUniqueKeyFieldResource, CoreMergeIndexesAdminHandlerTest, SpellingQueryConverterTest, XsltUpdateRequestHandlerTest, DistributedQueryElevationComponentTest, TestFuzzyAnalyzedSuggestions, TestReloadAndDeleteDocs, TestCSVResponseWriter, PreAnalyzedUpdateProcessorTest, TestZkChroot, TestSolrXmlPersistence, ResponseLogComponentTest, TestQueryUtils, HdfsBasicDistributedZk2Test, TestSurroundQueryParser, SpellPossibilityIteratorTest, TestWriterPerf, UUIDFieldTest, TestSort, ShowFileRequestHandlerTest, TestAtomicUpdateErrorCases, BadIndexSchemaTest, SolrCoreTest, HdfsSyncSliceTest, TestJmxIntegration, DocumentAnalysisRequestHandlerTest, TimeZoneUtilsTest, QueryParsingTest, TestSchemaSimilarityResource, PolyFieldTest, TestReplicationHandler, JsonLoaderTest, TestSearchPerf, DistributedTermsComponentTest, TestRangeQuery, UniqFieldsUpdateProcessorFactoryTest, NoCacheHeaderTest, ReturnFieldsTest, TestJmxMonitoredMap, SystemInfoHandlerTest, TestSolrQueryParserResource, TestOmitPositions, TestAddFieldRealTimeGet, TestLuceneMatchVersion, TestStressReorder, TestSchemaVersionResource, StressHdfsTest, LegacyHTMLStripCharFilterTest, HighlighterTest, CoreAdminCreateDiscoverTest, MinimalSchemaTest, ChaosMonkeySafeLeaderTest]
[junit4] Completed in 121.68s, 1 test, 1 error <<< FAILURES!
[...truncated 546 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:422: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:402: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:39: 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:451: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1230: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:873: There were test failures: 326 suites, 1448 tests, 2 errors, 39 ignored (5 assumptions)
Total time: 100 minutes 53 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.7.0) - Build # 893 -
Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/893/
Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.ShardSplitTest.testDistribSearch
Error Message:
Wrong doc count on shard1_1 expected:<35> but was:<34>
Stack Trace:
java.lang.AssertionError: Wrong doc count on shard1_1 expected:<35> but was:<34>
at __randomizedtesting.SeedInfo.seed([352825AF18E76197:B4CEABB76FB801AB]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.apache.solr.cloud.ShardSplitTest.checkDocCountsAndShardStates(ShardSplitTest.java:327)
at org.apache.solr.cloud.ShardSplitTest.splitByUniqueKeyTest(ShardSplitTest.java:201)
at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:111)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Build Log:
[...truncated 9846 lines...]
[junit4] Suite: org.apache.solr.cloud.ShardSplitTest
[junit4] 2> 1421476 T3325 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /x_qg/
[junit4] 2> 1421483 T3325 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-ShardSplitTest-1381157983757
[junit4] 2> 1421486 T3325 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1421488 T3326 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1421591 T3325 oasc.ZkTestServer.run start zk server on port:50258
[junit4] 2> 1421592 T3325 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1421603 T3332 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2bb4efc name:ZooKeeperConnection Watcher:127.0.0.1:50258 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1421604 T3325 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1421605 T3325 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1421618 T3325 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1421628 T3334 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@35ce03b5 name:ZooKeeperConnection Watcher:127.0.0.1:50258/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1421629 T3325 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1421630 T3325 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 1421642 T3325 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 1421652 T3325 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 1421660 T3325 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 1421669 T3325 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 1421670 T3325 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 1421682 T3325 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 1421683 T3325 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 1421692 T3325 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1421693 T3325 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1421701 T3325 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 1421702 T3325 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 1421710 T3325 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 1421712 T3325 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 1421721 T3325 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 1421723 T3325 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 1421733 T3325 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 1421734 T3325 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 1421744 T3325 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1421745 T3325 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1421754 T3325 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 1421755 T3325 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 1421767 T3325 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 1421769 T3325 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 1422315 T3325 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1422333 T3325 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50261
[junit4] 2> 1422334 T3325 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1422335 T3325 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1422336 T3325 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ShardSplitTest-controljetty-1381157984056
[junit4] 2> 1422338 T3325 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-controljetty-1381157984056/'
[junit4] 2> 1422398 T3325 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1381157984056/solr.xml
[junit4] 2> 1422531 T3325 oasc.CoreContainer.<init> New CoreContainer 101660806
[junit4] 2> 1422532 T3325 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ShardSplitTest-controljetty-1381157984056/]
[junit4] 2> 1422534 T3325 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1422535 T3325 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1422535 T3325 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1422536 T3325 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1422536 T3325 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1422537 T3325 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1422537 T3325 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1422538 T3325 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1422538 T3325 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1422539 T3325 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1422545 T3325 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1422546 T3325 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1422546 T3325 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50258/solr
[junit4] 2> 1422547 T3325 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1422550 T3325 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1422556 T3345 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@93f0dec name:ZooKeeperConnection Watcher:127.0.0.1:50258 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1422558 T3325 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1422564 T3325 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1422568 T3325 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1422575 T3347 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4be125be name:ZooKeeperConnection Watcher:127.0.0.1:50258/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1422575 T3325 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1422581 T3325 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1422593 T3325 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1422603 T3325 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1422610 T3325 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50261_x_qg
[junit4] 2> 1422613 T3325 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50261_x_qg
[junit4] 2> 1422622 T3325 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1422636 T3325 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1422643 T3325 oasc.Overseer.start Overseer (id=90515569624088579-127.0.0.1:50261_x_qg-n_0000000000) starting
[junit4] 2> 1422652 T3325 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1422661 T3349 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1422662 T3325 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1422670 T3325 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1422676 T3325 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1422687 T3348 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1422694 T3350 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1422695 T3350 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1422697 T3350 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1424198 T3348 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1424201 T3348 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:50261/x_qg",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:50261_x_qg",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1424202 T3348 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 1424202 T3348 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1424214 T3347 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> 1424703 T3350 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1424703 T3350 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ShardSplitTest-controljetty-1381157984056/collection1
[junit4] 2> 1424704 T3350 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 1424706 T3350 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1424706 T3350 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 1424709 T3350 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-controljetty-1381157984056/collection1/'
[junit4] 2> 1424711 T3350 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1381157984056/collection1/lib/classes/' to classloader
[junit4] 2> 1424712 T3350 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1381157984056/collection1/lib/README' to classloader
[junit4] 2> 1424784 T3350 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 1424856 T3350 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1424859 T3350 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1424873 T3350 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1425650 T3350 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1425654 T3350 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1425658 T3350 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1425669 T3350 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1425760 T3350 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1425761 T3350 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ShardSplitTest-controljetty-1381157984056/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1381157983756/control/data/
[junit4] 2> 1425761 T3350 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4d49e1ca
[junit4] 2> 1425763 T3350 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1381157983756/control/data
[junit4] 2> 1425764 T3350 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1381157983756/control/data/index/
[junit4] 2> 1425764 T3350 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1381157983756/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 1425766 T3350 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1381157983756/control/data/index
[junit4] 2> 1425767 T3350 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=18, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6377950261723787]
[junit4] 2> 1425769 T3350 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@46427ba5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@31775986),segFN=segments_1,generation=1}
[junit4] 2> 1425770 T3350 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1425780 T3350 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1425781 T3350 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1425782 T3350 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1425783 T3350 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1425783 T3350 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1425784 T3350 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1425785 T3350 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1425786 T3350 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1425787 T3350 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1425788 T3350 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1425789 T3350 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1425790 T3350 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1425791 T3350 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1425792 T3350 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1425793 T3350 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1425819 T3350 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1425832 T3350 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1425833 T3350 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1425835 T3350 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=736618904, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 1425836 T3350 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@46427ba5 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@31775986),segFN=segments_1,generation=1}
[junit4] 2> 1425837 T3350 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1425838 T3350 oass.SolrIndexSearcher.<init> Opening Searcher@36f17403 main
[junit4] 2> 1425849 T3351 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@36f17403 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1425850 T3350 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1425850 T3350 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50261/x_qg collection:control_collection shard:shard1
[junit4] 2> 1425851 T3350 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 1425854 T3350 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 1425876 T3350 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1425884 T3350 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1425885 T3350 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1425885 T3350 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50261/x_qg/collection1/
[junit4] 2> 1425885 T3350 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1425886 T3350 oasc.SyncStrategy.syncToMe http://127.0.0.1:50261/x_qg/collection1/ has no replicas
[junit4] 2> 1425886 T3350 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50261/x_qg/collection1/ shard1
[junit4] 2> 1425886 T3350 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 1427235 T3348 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1427255 T3347 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> 1427287 T3350 oasc.ZkController.register We are http://127.0.0.1:50261/x_qg/collection1/ and leader is http://127.0.0.1:50261/x_qg/collection1/
[junit4] 2> 1427287 T3350 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50261/x_qg
[junit4] 2> 1427288 T3350 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1427288 T3350 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1427288 T3350 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1427292 T3350 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1427295 T3325 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 1427295 T3325 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1427296 T3325 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1427297 T3325 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4] 2> 1427300 T3325 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1427304 T3354 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@625b9066 name:ZooKeeperConnection Watcher:127.0.0.1:50258/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1427304 T3325 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1427308 T3325 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1427317 T3325 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 1427798 T3325 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1427805 T3325 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50265
[junit4] 2> 1427807 T3325 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1427807 T3325 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1427808 T3325 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ShardSplitTest-jetty1-1381157989589
[junit4] 2> 1427808 T3325 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty1-1381157989589/'
[junit4] 2> 1427856 T3325 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1381157989589/solr.xml
[junit4] 2> 1427970 T3325 oasc.CoreContainer.<init> New CoreContainer 1401585206
[junit4] 2> 1427971 T3325 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ShardSplitTest-jetty1-1381157989589/]
[junit4] 2> 1427973 T3325 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1427974 T3325 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1427975 T3325 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1427975 T3325 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1427976 T3325 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1427976 T3325 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1427977 T3325 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1427978 T3325 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1427979 T3325 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1427979 T3325 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1427986 T3325 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1427987 T3325 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1427988 T3325 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50258/solr
[junit4] 2> 1427988 T3325 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1427990 T3325 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1427995 T3365 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14eb033f name:ZooKeeperConnection Watcher:127.0.0.1:50258 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1427996 T3325 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1428002 T3325 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1428006 T3325 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1428011 T3367 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4c0508ec name:ZooKeeperConnection Watcher:127.0.0.1:50258/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1428011 T3325 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1428025 T3325 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1428771 T3348 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1428773 T3348 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:50261/x_qg",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:50261_x_qg",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1428782 T3367 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> 1428782 T3354 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> 1428782 T3347 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> 1429036 T3325 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50265_x_qg
[junit4] 2> 1429040 T3325 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50265_x_qg
[junit4] 2> 1429049 T3347 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1429049 T3354 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1429049 T3367 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1429066 T3368 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1429067 T3368 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1429069 T3368 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1430297 T3348 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1430299 T3348 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:50265/x_qg",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:50265_x_qg",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1430299 T3348 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 1430300 T3348 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1430311 T3354 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> 1430312 T3347 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> 1430312 T3367 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> 1431078 T3368 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1431079 T3368 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ShardSplitTest-jetty1-1381157989589/collection1
[junit4] 2> 1431079 T3368 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1431081 T3368 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1431082 T3368 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1431085 T3368 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty1-1381157989589/collection1/'
[junit4] 2> 1431086 T3368 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1381157989589/collection1/lib/classes/' to classloader
[junit4] 2> 1431086 T3368 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1381157989589/collection1/lib/README' to classloader
[junit4] 2> 1431173 T3368 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 1431260 T3368 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1431264 T3368 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1431278 T3368 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1432002 T3368 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1432008 T3368 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1432012 T3368 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1432020 T3368 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1432088 T3368 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1432089 T3368 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ShardSplitTest-jetty1-1381157989589/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1381157983756/jetty1/
[junit4] 2> 1432089 T3368 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4d49e1ca
[junit4] 2> 1432090 T3368 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1381157983756/jetty1
[junit4] 2> 1432091 T3368 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1381157983756/jetty1/index/
[junit4] 2> 1432091 T3368 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1381157983756/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 1432092 T3368 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1381157983756/jetty1/index
[junit4] 2> 1432093 T3368 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=18, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6377950261723787]
[junit4] 2> 1432093 T3368 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@115c958a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1eb7d3f1),segFN=segments_1,generation=1}
[junit4] 2> 1432094 T3368 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1432098 T3368 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1432098 T3368 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1432099 T3368 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1432099 T3368 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1432099 T3368 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1432099 T3368 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1432100 T3368 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1432100 T3368 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1432101 T3368 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1432101 T3368 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1432102 T3368 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1432102 T3368 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1432103 T3368 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1432104 T3368 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1432104 T3368 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1432115 T3368 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1432120 T3368 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1432120 T3368 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1432122 T3368 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=736618904, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 1432123 T3368 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@115c958a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1eb7d3f1),segFN=segments_1,generation=1}
[junit4] 2> 1432124 T3368 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1432124 T3368 oass.SolrIndexSearcher.<init> Opening Searcher@197ce6db main
[junit4] 2> 1432132 T3369 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@197ce6db main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1432136 T3368 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1432137 T3368 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50265/x_qg collection:collection1 shard:shard1
[junit4] 2> 1432137 T3368 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 1432140 T3368 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 1432161 T3368 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1432169 T3368 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1432169 T3368 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1432170 T3368 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50265/x_qg/collection1/
[junit4] 2> 1432170 T3368 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1432170 T3368 oasc.SyncStrategy.syncToMe http://127.0.0.1:50265/x_qg/collection1/ has no replicas
[junit4] 2> 1432171 T3368 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50265/x_qg/collection1/ shard1
[junit4] 2> 1432171 T3368 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 1433332 T3348 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1433363 T3347 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> 1433363 T3367 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> 1433363 T3354 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> 1433389 T3368 oasc.ZkController.register We are http://127.0.0.1:50265/x_qg/collection1/ and leader is http://127.0.0.1:50265/x_qg/collection1/
[junit4] 2> 1433390 T3368 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50265/x_qg
[junit4] 2> 1433390 T3368 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1433390 T3368 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1433391 T3368 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1433395 T3368 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1433398 T3325 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 1433399 T3325 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1433399 T3325 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1433871 T3325 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1433877 T3325 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50268
[junit4] 2> 1433881 T3325 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1433881 T3325 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1433882 T3325 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ShardSplitTest-jetty2-1381157995673
[junit4] 2> 1433882 T3325 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty2-1381157995673/'
[junit4] 2> 1433929 T3325 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1381157995673/solr.xml
[junit4] 2> 1434013 T3325 oasc.CoreContainer.<init> New CoreContainer 1629370803
[junit4] 2> 1434014 T3325 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ShardSplitTest-jetty2-1381157995673/]
[junit4] 2> 1434015 T3325 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1434015 T3325 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1434016 T3325 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1434016 T3325 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1434016 T3325 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1434017 T3325 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1434017 T3325 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1434017 T3325 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1434017 T3325 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1434018 T3325 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1434022 T3325 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1434024 T3325 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1434024 T3325 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50258/solr
[junit4] 2> 1434024 T3325 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1434026 T3325 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1434029 T3381 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@49ba345d name:ZooKeeperConnection Watcher:127.0.0.1:50258 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1434031 T3325 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1434035 T3325 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1434039 T3325 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1434046 T3383 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2e8ffc32 name:ZooKeeperConnection Watcher:127.0.0.1:50258/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1434047 T3325 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1434058 T3325 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1434883 T3348 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1434885 T3348 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:50265/x_qg",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:50265_x_qg",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 1434896 T3367 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> 1434897 T3347 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> 1434897 T3354 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> 1434897 T3383 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> 1435067 T3325 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50268_x_qg
[junit4] 2> 1435070 T3325 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50268_x_qg
[junit4] 2> 1435076 T3383 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1435077 T3354 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1435077 T3347 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1435077 T3367 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 1435092 T3384 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1435092 T3384 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1435094 T3384 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1436415 T3348 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1436417 T3348 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:50268/x_qg",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:50268_x_qg",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 1436417 T3348 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 1436418 T3348 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 1436433 T3354 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> 1436434 T3383 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> 1436434 T3347 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> 1436434 T3367 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> 1437097 T3384 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1437097 T3384 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ShardSplitTest-jetty2-1381157995673/collection1
[junit4] 2> 1437098 T3384 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1437100 T3384 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1437100 T3384 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1437103 T3384 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ShardSplitTest-jetty2-1381157995673/collection1/'
[junit4] 2> 1437106 T3384 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1381157995673/collection1/lib/classes/' to classloader
[junit4] 2> 1437107 T3384 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1381157995673/collection1/lib/README' to classloader
[junit4] 2> 1437196 T3384 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 1437297 T3384 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1437301 T3384 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1437315 T3384 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1438035 T3384 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1438039 T3384 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1438044 T3384 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1438051 T3384 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1438115 T3384 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1438116 T3384 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ShardSplitTest-jetty2-1381157995673/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1381157983756/jetty2/
[junit4] 2> 1438116 T3384 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4d49e1ca
[junit4] 2> 1438117 T3384 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1381157983756/jetty2
[junit4] 2> 1438117 T3384 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1381157983756/jetty2/index/
[junit4] 2> 1438118 T3384 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1381157983756/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 1438119 T3384 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1381157983756/jetty2/index
[junit4] 2> 1438120 T3384 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=18, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6377950261723787]
[junit4] 2> 1438121 T3384 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@68e1503f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@152fd558),segFN=segments_1,generation=1}
[junit4] 2> 1438121 T3384 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1438128 T3384 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1438129 T3384 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1438129 T3384 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1438130 T3384 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1438130 T3384 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1438131 T3384 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1438132 T3384 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1438132 T3384 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1438132 T3384 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1438133 T3384 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1438134 T3384 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1438135 T3384 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1438135 T3384 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1438136 T3384 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1438137 T3384 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1438151 T3384 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1438158 T3384 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1438158 T3384 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1438160 T3384 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=736618904, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 1438161 T3384 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@68e1503f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@152fd558),segFN=segments_1,generation=1}
[junit4] 2> 1438161 T3384 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1438162 T3384 oass.SolrIndexSearcher.<init> Opening Searcher@102243c9 main
[junit4] 2> 1438171 T3385 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@102243c9 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1438175 T3384 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1438175 T3384 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50268/x_qg collection:collection1 shard:shard2
[junit4] 2> 1438176 T3384 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 1438179 T3384 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 1438195 T3384 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 1438203 T3384 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1438203 T3384 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1438204 T3384 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50268/x_qg/collection1/
[junit4] 2> 1438204 T3384 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1438205 T3384 oasc.SyncStrategy.syncToMe http://127.0.0.1:50268/x_qg/collection1/ has no replicas
[junit4] 2> 1438205 T3384 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50268/x_qg/collection1/ shard2
[junit4] 2> 1438205 T3384 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 1439452 T3348 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1439471 T3367 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> 1439472 T3354 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> 1439472 T3347 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> 1439472 T3383 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> 1439499 T3384 oasc.ZkController.register We are http://127.0.0.1:50268/x_qg/collection1/ and leader is http://127.0.0.1:50268/x_qg/collection1/
[junit4] 2> 1439500 T3384 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50268/x_qg
[junit4] 2> 1439500 T3384 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1439500 T3384 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1439500 T3384 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1439504 T3384 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1439508 T3325 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 1439508 T3325 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1439509 T3325 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1439918 T3325 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1439923 T3325 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50271
[junit4] 2> 1439925 T3325 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1439926 T3325 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1439926 T3325 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1381158001782
[junit4] 2> 1439927 T3325 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1381158001782/'
[junit4] 2> 1439970 T3325 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1381158001782/solr.xml
[junit4] 2> 1440069 T3325 oasc.CoreContainer.<init> New CoreContainer 999123970
[junit4] 2> 1440070 T3325 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1381158001782/]
[junit4] 2> 1440073 T3325 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1440073 T3325 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1440074 T3325 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1440074 T3325 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1440075 T3325 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1440075 T3325 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1440076 T3325 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1440076 T3325 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1440077 T3325 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1440077 T3325 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1440083 T3325 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1440083 T3325 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1440085 T3325 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50258/solr
[junit4] 2> 1440085 T3325 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1440087 T3325 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1440091 T3397 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@21df6b4f name:ZooKeeperConnection Watcher:127.0.0.1:50258 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1440092 T3325 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1440096 T3325 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1440100 T3325 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1440104 T3399 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@992e34e name:ZooKeeperConnection Watcher:127.0.0.1:50258/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1440104 T3325 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1440116 T3325 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1440991 T3348 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1440993 T3348 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:50268/x_qg",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:50268_x_qg",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 1441007 T3367 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> 1441007 T3354 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> 1441008 T3383 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> 1441008 T3347 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> 1441008 T3399 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> 1441126 T3325 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50271_x_qg
[junit4] 2> 1441130 T3325 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50271_x_qg
[junit4] 2> 1441140 T3347 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1441140 T3383 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1441141 T3367 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1441142 T3399 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1441142 T3354 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 1441158 T3400 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1441159 T3400 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1441162 T3400 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1442527 T3348 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1442529 T3348 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:50271/x_qg",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:50271_x_qg",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node3"}
[junit4] 2> 1442529 T3348 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 1442530 T3348 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1442540 T3383 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> 1442540 T3347 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> 1442540 T3399 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> 1442540 T3367 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> 1442540 T3354 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> 1443165 T3400 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1443165 T3400 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1381158001782/collection1
[junit4] 2> 1443165 T3400 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1443167 T3400 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1443168 T3400 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1443170 T3400 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1381158001782/collection1/'
[junit4] 2> 1443172 T3400 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1381158001782/collection1/lib/classes/' to classloader
[junit4] 2> 1443173 T3400 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1381158001782/collection1/lib/README' to classloader
[junit4] 2> 1443257 T3400 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 1443344 T3400 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1443347 T3400 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1443360 T3400 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1444142 T3400 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1444147 T3400 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1444150 T3400 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1444163 T3400 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1444252 T3400 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 1444253 T3400 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1381158001782/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1381157983756/jetty3/
[junit4] 2> 1444254 T3400 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4d49e1ca
[junit4] 2> 1444255 T3400 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1381157983756/jetty3
[junit4] 2> 1444255 T3400 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1381157983756/jetty3/index/
[junit4] 2> 1444255 T3400 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1381157983756/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 1444257 T3400 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1381157983756/jetty3/index
[junit4] 2> 1444258 T3400 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=18, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6377950261723787]
[junit4] 2> 1444260 T3400 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@5a06e64 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7ce52885),segFN=segments_1,generation=1}
[junit4] 2> 1444260 T3400 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1444268 T3400 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1444269 T3400 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1444269 T3400 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1444270 T3400 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1444270 T3400 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1444271 T3400 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1444272 T3400 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1444272 T3400 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1444273 T3400 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1444274 T3400 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1444276 T3400 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1444276 T3400 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1444277 T3400 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1444278 T3400 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1444279 T3400 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1444294 T3400 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1444301 T3400 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1444302 T3400 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1444303 T3400 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=736618904, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 1444304 T3400 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(org.apache.lucene.store.RAMDirectory@5a06e64 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7ce52885),segFN=segments_1,generation=1}
[junit4] 2> 1444304 T3400 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1444305 T3400 oass.SolrIndexSearcher.<init> Opening Searcher@5e639879 main
[junit4] 2> 1444317 T3401 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5e639879 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1444322 T3400 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1444322 T3400 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50271/x_qg collection:collection1 shard:shard1
[junit4] 2> 1444323 T3400 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 1444336 T3400 oasc.ZkController.register We are http://127.0.0.1:50271/x_qg/collection1/ and leader is http://127.0.0.1:50265/x_qg/collection1/
[junit4] 2> 1444336 T3400 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50271/x_qg
[junit4] 2> 1444336 T3400 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 1444337 T3400 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C4396 name=collection1 org.apache.solr.core.SolrCore@46bb4ba9 url=http://127.0.0.1:50271/x_qg/collection1 node=127.0.0.1:50271_x_qg C4396_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:50271/x_qg, core=collection1, node_name=127.0.0.1:50271_x_qg}
[junit4] 2> 1444338 T3402 C4396 P50271 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 1444339 T3402 C4396 P50271 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 1444339 T3400 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1444341 T3402 C4396 P50271 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 1444343 T3402 C4396 P50271 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1444346 T3325 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 1444347 T3325 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1444347 T3402 C4396 P50271 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1444348 T3325 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1444355 T3362 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 1444851 T3325 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1444859 T3325 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50275
[junit4] 2> 1444861 T3325 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1444862 T3325 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1444863 T3325 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1381158006623
[junit4] 2> 1444863 T3325 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1381158006623/'
[junit4] 2> 1444914 T3325 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1381158006623/solr.xml
[junit4] 2> 1445023 T3325 oasc.CoreContainer.<init> New CoreContainer 687130796
[junit4] 2> 1445023 T3325 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1381158006623/]
[junit4] 2> 1445026 T3325 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1445026 T3325 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1445027 T3325 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1445027 T3325 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1445028 T3325 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1445028 T3325 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1445029 T3325 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1445029 T3325 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1445030 T3325 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1445031 T3325 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1445038 T3325 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 1445039 T3325 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 1445039 T3325 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50258/solr
[junit4] 2> 1445040 T3325 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1445044 T3325 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1445049 T3414 oascc.ConnectionManager.process Watcher org.apac
[...truncated too long message...]
asu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 1488297 T3325 oasc.SolrCore.closeSearcher [collection1_shard1_0_replica2] Closing main searcher on request.
[junit4] 2> 1488298 T3325 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 1488298 T3325 oasc.CachingDirectoryFactory.closeCacheValue looking to close ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1381158006623/collection1_shard1_0_replica2/data [CachedDir<<refCount=0;path=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1381158006623/collection1_shard1_0_replica2/data;done=false>>]
[junit4] 2> 1488299 T3325 oasc.CachingDirectoryFactory.close Closing directory: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1381158006623/collection1_shard1_0_replica2/data
[junit4] 2> 1488299 T3325 oasc.CachingDirectoryFactory.closeCacheValue looking to close ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1381158006623/collection1_shard1_0_replica2/data/index.20131007170030820 [CachedDir<<refCount=0;path=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1381158006623/collection1_shard1_0_replica2/data/index.20131007170030820;done=false>>]
[junit4] 2> 1488300 T3325 oasc.CachingDirectoryFactory.close Closing directory: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1381158006623/collection1_shard1_0_replica2/data/index.20131007170030820
[junit4] 2> 1488301 T3490 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=90515569624088588-127.0.0.1:50275_x_qg-n_0000000004) am no longer a leader.
[junit4] 2> 1488305 T3416 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1488308 T3471 oascc.ZkStateReader$3.process Updating live nodes... (0)
[junit4] 2> 1488321 T3325 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/x_qg,null}
[junit4] 2> 1488395 T3325 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4] 2> 1488399 T3325 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:50258 50258
[junit4] 2> 1488603 T3471 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@203ccb1a name:ZooKeeperConnection Watcher:127.0.0.1:50258/solr got event WatchedEvent state:Disconnected type:None path:null path:null type:None
[junit4] 2> 1488604 T3471 oascc.ConnectionManager.process Client->ZooKeeper status change trigger but we are already closed
[junit4] 2> 1488604 T3325 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 50261
[junit4] 2> !!!! WARNING: best effort to remove /Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-1381157983756 FAILED !!!!!
[junit4] 2> 1488606 T3325 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4] 2> 1488606 T3325 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:50258 50258
[junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election (1)
[junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election/90515569624088579-core_node1-n_0000000000 (0)
[junit4] 1> /solr/collections/control_collection/leaders (1)
[junit4] 1> /solr/collections/control_collection/leaders/shard1 (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:50261_x_qg",
[junit4] 1> "base_url":"http://127.0.0.1:50261/x_qg"}
[junit4] 1> /solr/overseer_elect (2)
[junit4] 1> /solr/overseer_elect/election (5)
[junit4] 1> /solr/overseer_elect/election/90515569624088579-127.0.0.1:50261_x_qg-n_0000000000 (0)
[junit4] 1> /solr/overseer_elect/election/90515569624088584-127.0.0.1:50268_x_qg-n_0000000002 (0)
[junit4] 1> /solr/overseer_elect/election/90515569624088586-127.0.0.1:50271_x_qg-n_0000000003 (0)
[junit4] 1> /solr/overseer_elect/election/90515569624088582-127.0.0.1:50265_x_qg-n_0000000001 (0)
[junit4] 1> /solr/overseer_elect/election/90515569624088588-127.0.0.1:50275_x_qg-n_0000000004 (0)
[junit4] 1> /solr/overseer_elect/leader (0)
[junit4] 1> DATA:
[junit4] 1> {"id":"90515569624088579-127.0.0.1:50261_x_qg-n_0000000000"}
[junit4] 1> /zookeeper (1)
[junit4] 1> DATA:
[junit4] 1>
[junit4] 1>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ShardSplitTest -Dtests.method=testDistribSearch -Dtests.seed=352825AF18E76197 -Dtests.slow=true -Dtests.locale=is -Dtests.timezone=Europe/Oslo -Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 67.1s | ShardSplitTest.testDistribSearch <<<
[junit4] > Throwable #1: java.lang.AssertionError: Wrong doc count on shard1_1 expected:<35> but was:<34>
[junit4] > at __randomizedtesting.SeedInfo.seed([352825AF18E76197:B4CEABB76FB801AB]:0)
[junit4] > at org.apache.solr.cloud.ShardSplitTest.checkDocCountsAndShardStates(ShardSplitTest.java:327)
[junit4] > at org.apache.solr.cloud.ShardSplitTest.splitByUniqueKeyTest(ShardSplitTest.java:201)
[junit4] > at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:111)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4] 2> 1488617 T3325 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 67149 T3324 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Lucene46: {id=Pulsing41(freqCutoff=20 minBlockSize=22 maxBlockSize=96), _version_=PostingsFormat(name=Memory doPackFST= true), n_ti=PostingsFormat(name=TestBloomFilteredLucene41Postings)}, docValues:{}, sim=DefaultSimilarity, locale=is, timezone=Europe/Oslo
[junit4] 2> NOTE: Mac OS X 10.8.4 x86_64/Oracle Corporation 1.7.0_40 (64-bit)/cpus=2,threads=1,free=356446360,total=519438336
[junit4] 2> NOTE: All tests run in this JVM: [RegexBoostProcessorTest, TestDocumentBuilder, LeaderElectionTest, DateMathParserTest, TestCSVResponseWriter, TestSearchPerf, StandardRequestHandlerTest, TestMultiCoreConfBootstrap, IndexBasedSpellCheckerTest, StatsComponentTest, TestBinaryField, SliceStateUpdateTest, OverseerCollectionProcessorTest, TestHashPartitioner, TestExtendedDismaxParser, InfoHandlerTest, TestZkChroot, TestRandomFaceting, StatelessScriptUpdateProcessorFactoryTest, TermVectorComponentTest, DirectSolrConnectionTest, DocValuesMultiTest, AnalysisAfterCoreReloadTest, TestArbitraryIndexDir, SimpleFacetsTest, TestReplicationHandler, TestMergePolicyConfig, MBeansHandlerTest, PathHierarchyTokenizerFactoryTest, ShardRoutingTest, TestStressLucene, TestIndexSearcher, TestAddFieldRealTimeGet, CollectionsAPIDistributedZkTest, TestRealTimeGet, CoreContainerCoreInitFailuresTest, SolrPluginUtilsTest, JSONWriterTest, TestSolrDeletionPolicy2, TestQuerySenderNoQuery, ShardRoutingCustomTest, DisMaxRequestHandlerTest, TestFastLRUCache, TermsComponentTest, HighlighterConfigTest, SimplePostToolTest, TestJmxIntegration, CopyFieldTest, TestQueryTypes, DeleteShardTest, TestWordDelimiterFilterFactory, HighlighterTest, TestSweetSpotSimilarityFactory, ClusterStateUpdateTest, TestSolrXmlPersistor, OpenExchangeRatesOrgProviderTest, ConvertedLegacyTest, TestUpdate, SolrIndexConfigTest, LoggingHandlerTest, TestSurroundQueryParser, UnloadDistributedZkTest, DistributedSpellCheckComponentTest, SuggesterTSTTest, CurrencyFieldOpenExchangeTest, TestAnalyzedSuggestions, CustomCollectionTest, TestNonNRTOpen, BasicDistributedZkTest, UpdateParamsTest, TestDynamicFieldResource, FileUtilsTest, RequestHandlersTest, DocumentAnalysisRequestHandlerTest, ResponseLogComponentTest, PrimUtilsTest, TestLRUCache, AssignTest, LegacyHTMLStripCharFilterTest, TestFuzzyAnalyzedSuggestions, HdfsDirectoryTest, HdfsRecoveryZkTest, ShardSplitTest]
[junit4] Completed in 67.98s, 1 test, 1 failure <<< FAILURES!
[...truncated 743 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:422: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:402: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/build.xml:39: 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:451: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1230: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:873: There were test failures: 326 suites, 1448 tests, 1 failure, 39 ignored (5 assumptions)
Total time: 101 minutes 29 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure