You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/03/24 03:16:00 UTC
[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.8.0) - Build # 1402 -
Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/1402/
Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
2 tests failed.
REGRESSION: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDistribSearch
Error Message:
deletecollection the collection time out:180s
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: deletecollection the collection time out:180s
at __randomizedtesting.SeedInfo.seed([CEE5E0C435A54112:4F036EDC42FA212E]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:504)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:203)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:199)
at org.apache.solr.client.solrj.request.CollectionAdminRequest.process(CollectionAdminRequest.java:300)
at org.apache.solr.client.solrj.request.CollectionAdminRequest.deleteCollection(CollectionAdminRequest.java:441)
at org.apache.solr.client.solrj.request.CollectionAdminRequest.deleteCollection(CollectionAdminRequest.java:431)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testSolrJAPICalls(CollectionsAPIDistributedZkTest.java:321)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:204)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:870)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:483)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1617)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
at java.lang.Thread.run(Thread.java:744)
REGRESSION: org.apache.solr.cloud.RecoveryZkTest.testDistribSearch
Error Message:
There are still nodes recoverying - waited for 90 seconds
Stack Trace:
java.lang.AssertionError: There are still nodes recoverying - waited for 90 seconds
at __randomizedtesting.SeedInfo.seed([CEE5E0C435A54112:4F036EDC42FA212E]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.AbstractDistribZkTestBase.waitForRecoveriesToFinish(AbstractDistribZkTestBase.java:177)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForRecoveriesToFinish(AbstractFullDistribZkTestBase.java:732)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.waitForThingsToLevelOut(AbstractFullDistribZkTestBase.java:1495)
at org.apache.solr.cloud.RecoveryZkTest.doTest(RecoveryZkTest.java:103)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:870)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:483)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1617)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:826)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:862)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:876)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:783)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:443)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:835)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:771)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:782)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:359)
at java.lang.Thread.run(Thread.java:744)
Build Log:
[...truncated 10487 lines...]
[junit4] Suite: org.apache.solr.cloud.RecoveryZkTest
[junit4] 2> 412667 T1638 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
[junit4] 2> 412667 T1638 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /rt_jpy/tu
[junit4] 2> 412688 T1638 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solrtest-RecoveryZkTest-1395621324666
[junit4] 2> 412689 T1638 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 412690 T1639 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 412791 T1638 oasc.ZkTestServer.run start zk server on port:53340
[junit4] 2> 412793 T1638 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 412812 T1645 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5d81ef61 name:ZooKeeperConnection Watcher:127.0.0.1:53340 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 412813 T1638 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 412813 T1638 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 412826 T1638 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 412847 T1647 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2b72bdd5 name:ZooKeeperConnection Watcher:127.0.0.1:53340/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 412847 T1638 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 412848 T1638 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 412854 T1638 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 412860 T1638 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 412864 T1638 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 412878 T1638 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 412879 T1638 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 412888 T1638 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 412889 T1638 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 412899 T1638 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 412900 T1638 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 412906 T1638 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 412907 T1638 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 412913 T1638 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 412914 T1638 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 412919 T1638 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 412920 T1638 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 412926 T1638 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 412927 T1638 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 412934 T1638 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 412935 T1638 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 412941 T1638 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 412943 T1638 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 412949 T1638 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 412949 T1638 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 412955 T1638 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 412956 T1638 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 412965 T1638 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 412974 T1649 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a620fd0 name:ZooKeeperConnection Watcher:127.0.0.1:53340/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 412975 T1638 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 414433 T1638 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 414442 T1638 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 414447 T1638 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:53344
[junit4] 2> 414451 T1638 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 414452 T1638 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 414452 T1638 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.RecoveryZkTest-controljetty-1395621324957
[junit4] 2> 414452 T1638 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.RecoveryZkTest-controljetty-1395621324957/'
[junit4] 2> 414498 T1638 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1395621324957/solr.xml
[junit4] 2> 414527 T1638 oasc.CoreContainer.<init> New CoreContainer 465058038
[junit4] 2> 414528 T1638 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.RecoveryZkTest-controljetty-1395621324957/]
[junit4] 2> 414529 T1638 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 414529 T1638 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 414529 T1638 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 414530 T1638 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 414530 T1638 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 414531 T1638 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 414531 T1638 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 414531 T1638 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 414532 T1638 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 414537 T1638 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 414538 T1638 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 414539 T1638 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 414539 T1638 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53340/solr
[junit4] 2> 414540 T1638 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 414542 T1638 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 414556 T1660 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55c06eab name:ZooKeeperConnection Watcher:127.0.0.1:53340 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 414556 T1638 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 414573 T1638 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 414573 T1662 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@55519851 name:ZooKeeperConnection Watcher:127.0.0.1:53340/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 414574 T1638 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 414578 T1638 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 414588 T1638 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 414593 T1638 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 414600 T1638 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 414606 T1638 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 414613 T1638 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 414616 T1638 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53344_rt_jpy%2Ftu
[junit4] 2> 414618 T1638 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53344_rt_jpy%2Ftu
[junit4] 2> 414623 T1638 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 414626 T1638 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 414634 T1638 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:53344_rt_jpy%2Ftu
[junit4] 2> 414634 T1638 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 414637 T1638 oasc.Overseer.start Overseer (id=91463439133638660-127.0.0.1:53344_rt_jpy%2Ftu-n_0000000000) starting
[junit4] 2> 414643 T1638 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 414661 T1664 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 414662 T1638 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 414663 T1664 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 414668 T1638 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 414672 T1638 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 414677 T1663 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 414683 T1665 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
[junit4] 2> 414684 T1665 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 414686 T1662 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 414686 T1665 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 414688 T1663 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 414689 T1663 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:53344/rt_jpy/tu",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:53344_rt_jpy%2Ftu",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 414689 T1663 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 414689 T1663 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 414693 T1662 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 414695 T1662 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> 415688 T1665 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 415688 T1665 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.RecoveryZkTest-controljetty-1395621324957/collection1
[junit4] 2> 415688 T1665 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 415689 T1665 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 415689 T1665 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 415691 T1665 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 415691 T1665 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.RecoveryZkTest-controljetty-1395621324957/collection1/'
[junit4] 2> 415693 T1665 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1395621324957/collection1/lib/.svn/' to classloader
[junit4] 2> 415693 T1665 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1395621324957/collection1/lib/classes/' to classloader
[junit4] 2> 415694 T1665 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1395621324957/collection1/lib/README' to classloader
[junit4] 2> 415764 T1665 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 415803 T1665 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 415806 T1665 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 415814 T1665 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 416035 T1665 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 416036 T1665 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 416038 T1665 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 416044 T1665 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 416106 T1665 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 416107 T1665 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.RecoveryZkTest-controljetty-1395621324957/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1395621324665/control/data/
[junit4] 2> 416108 T1665 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@cb4b3e
[junit4] 2> 416110 T1665 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1395621324665/control/data
[junit4] 2> 416110 T1665 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1395621324665/control/data/index/
[junit4] 2> 416110 T1665 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1395621324665/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 416111 T1665 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1395621324665/control/data/index
[junit4] 2> 416111 T1665 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=13, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.37212807856479335]
[junit4] 2> 416113 T1665 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@bfed4f6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ff007d8),segFN=segments_1,generation=1}
[junit4] 2> 416113 T1665 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 416119 T1665 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 416119 T1665 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 416120 T1665 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 416120 T1665 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 416121 T1665 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 416121 T1665 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 416122 T1665 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 416122 T1665 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 416122 T1665 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 416123 T1665 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 416123 T1665 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 416124 T1665 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 416124 T1665 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 416125 T1665 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 416126 T1665 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 416126 T1665 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 416135 T1665 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 416141 T1665 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 416141 T1665 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 416141 T1665 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=17.1318359375, floorSegmentMB=1.5439453125, forceMergeDeletesPctAllowed=11.826569833384498, segmentsPerTier=14.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 416142 T1665 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@bfed4f6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@3ff007d8),segFN=segments_1,generation=1}
[junit4] 2> 416142 T1665 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 416142 T1665 oass.SolrIndexSearcher.<init> Opening Searcher@1588a49b[collection1] main
[junit4] 2> 416144 T1666 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1588a49b[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 416146 T1665 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 416148 T1638 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 416149 T1638 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 416151 T1669 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:53344/rt_jpy/tu collection:control_collection shard:shard1
[junit4] 2> 416154 T1638 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 416162 T1671 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@394d701 name:ZooKeeperConnection Watcher:127.0.0.1:53340/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 416162 T1669 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 416163 T1638 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 416166 T1638 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 416172 T1638 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 416188 T1669 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 416199 T1662 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 416203 T1669 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 416203 T1669 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C600 name=collection1 org.apache.solr.core.SolrCore@ee99e9d url=https://127.0.0.1:53344/rt_jpy/tu/collection1 node=127.0.0.1:53344_rt_jpy%2Ftu C600_STATE=coll:control_collection core:collection1 props:{state=down, base_url=https://127.0.0.1:53344/rt_jpy/tu, core=collection1, node_name=127.0.0.1:53344_rt_jpy%2Ftu}
[junit4] 2> 416204 T1669 C600 P53344 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:53344/rt_jpy/tu/collection1/
[junit4] 2> 416204 T1669 C600 P53344 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 416205 T1669 C600 P53344 oasc.SyncStrategy.syncToMe https://127.0.0.1:53344/rt_jpy/tu/collection1/ has no replicas
[junit4] 2> 416205 T1669 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:53344/rt_jpy/tu/collection1/ shard1
[junit4] 2> 416206 T1669 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 416209 T1663 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 416222 T1662 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 416229 T1671 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> 416229 T1662 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> 416291 T1663 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 416317 T1662 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 416431 T1662 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> 416431 T1671 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> 416479 T1669 oasc.ZkController.register We are https://127.0.0.1:53344/rt_jpy/tu/collection1/ and leader is https://127.0.0.1:53344/rt_jpy/tu/collection1/
[junit4] 2> 416479 T1669 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:53344/rt_jpy/tu
[junit4] 2> 416479 T1669 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 416479 T1669 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
[junit4] 2> 416480 T1669 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 416487 T1662 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 416488 T1662 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 416488 T1662 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 416493 T1669 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 416496 T1663 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 416501 T1663 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"https://127.0.0.1:53344/rt_jpy/tu",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:53344_rt_jpy%2Ftu",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 416515 T1662 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 416626 T1671 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> 416628 T1662 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> 417991 T1638 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 417992 T1638 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 418001 T1638 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 418004 T1638 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:53348
[junit4] 2> 418009 T1638 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 418009 T1638 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 418010 T1638 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.RecoveryZkTest-jetty1-1395621328150
[junit4] 2> 418011 T1638 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.RecoveryZkTest-jetty1-1395621328150/'
[junit4] 2> 418048 T1638 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1395621328150/solr.xml
[junit4] 2> 418080 T1638 oasc.CoreContainer.<init> New CoreContainer 1438541488
[junit4] 2> 418080 T1638 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.RecoveryZkTest-jetty1-1395621328150/]
[junit4] 2> 418081 T1638 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 418082 T1638 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 418082 T1638 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 418082 T1638 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 418083 T1638 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 418083 T1638 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 418083 T1638 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 418084 T1638 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 418085 T1638 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 418099 T1638 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 418099 T1638 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 418100 T1638 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 418100 T1638 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53340/solr
[junit4] 2> 418101 T1638 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 418106 T1638 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 418109 T1682 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2ae5b5d0 name:ZooKeeperConnection Watcher:127.0.0.1:53340 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 418109 T1638 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 418118 T1638 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 418119 T1684 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1bc48e2 name:ZooKeeperConnection Watcher:127.0.0.1:53340/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 418120 T1638 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 418137 T1638 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 419144 T1638 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53348_rt_jpy%2Ftu
[junit4] 2> 419149 T1638 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53348_rt_jpy%2Ftu
[junit4] 2> 419156 T1662 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 419157 T1684 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 419158 T1671 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 419170 T1685 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 419170 T1685 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 419172 T1662 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 419172 T1662 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 419172 T1662 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 419173 T1685 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 419176 T1663 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 419179 T1663 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:53348/rt_jpy/tu",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:53348_rt_jpy%2Ftu",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 419179 T1663 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
[junit4] 2> 419179 T1663 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 419186 T1662 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 419188 T1662 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> 419189 T1671 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> 419189 T1684 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> 420173 T1685 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 420173 T1685 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.RecoveryZkTest-jetty1-1395621328150/collection1
[junit4] 2> 420173 T1685 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 420175 T1685 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 420175 T1685 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 420176 T1685 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 420177 T1685 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.RecoveryZkTest-jetty1-1395621328150/collection1/'
[junit4] 2> 420178 T1685 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1395621328150/collection1/lib/.svn/' to classloader
[junit4] 2> 420180 T1685 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1395621328150/collection1/lib/classes/' to classloader
[junit4] 2> 420180 T1685 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1395621328150/collection1/lib/README' to classloader
[junit4] 2> 420225 T1685 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 420241 T1685 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 420243 T1685 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 420256 T1685 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 420460 T1685 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 420461 T1685 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 420463 T1685 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 420470 T1685 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 420527 T1685 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 420528 T1685 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.RecoveryZkTest-jetty1-1395621328150/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1395621324665/jetty1/
[junit4] 2> 420528 T1685 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@cb4b3e
[junit4] 2> 420529 T1685 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1395621324665/jetty1
[junit4] 2> 420529 T1685 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1395621324665/jetty1/index/
[junit4] 2> 420529 T1685 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1395621324665/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 420530 T1685 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1395621324665/jetty1/index
[junit4] 2> 420530 T1685 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=13, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.37212807856479335]
[junit4] 2> 420531 T1685 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@dbbcd9a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@54bd423c),segFN=segments_1,generation=1}
[junit4] 2> 420531 T1685 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 420538 T1685 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 420538 T1685 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 420538 T1685 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 420539 T1685 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 420539 T1685 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 420539 T1685 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 420539 T1685 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 420540 T1685 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 420540 T1685 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 420540 T1685 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 420540 T1685 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 420541 T1685 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 420541 T1685 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 420542 T1685 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 420542 T1685 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 420542 T1685 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 420549 T1685 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 420551 T1685 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 420551 T1685 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 420552 T1685 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=17.1318359375, floorSegmentMB=1.5439453125, forceMergeDeletesPctAllowed=11.826569833384498, segmentsPerTier=14.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 420552 T1685 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@dbbcd9a lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@54bd423c),segFN=segments_1,generation=1}
[junit4] 2> 420552 T1685 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 420552 T1685 oass.SolrIndexSearcher.<init> Opening Searcher@31275216[collection1] main
[junit4] 2> 420558 T1686 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@31275216[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 420560 T1685 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 420561 T1638 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 420561 T1638 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 420568 T1689 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:53348/rt_jpy/tu collection:collection1 shard:shard1
[junit4] 2> 420575 T1689 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 420601 T1689 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 420616 T1662 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 420617 T1689 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 420618 T1689 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C601 name=collection1 org.apache.solr.core.SolrCore@43c9c099 url=https://127.0.0.1:53348/rt_jpy/tu/collection1 node=127.0.0.1:53348_rt_jpy%2Ftu C601_STATE=coll:collection1 core:collection1 props:{state=down, base_url=https://127.0.0.1:53348/rt_jpy/tu, core=collection1, node_name=127.0.0.1:53348_rt_jpy%2Ftu}
[junit4] 2> 420618 T1689 C601 P53348 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:53348/rt_jpy/tu/collection1/
[junit4] 2> 420619 T1689 C601 P53348 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 420619 T1689 C601 P53348 oasc.SyncStrategy.syncToMe https://127.0.0.1:53348/rt_jpy/tu/collection1/ has no replicas
[junit4] 2> 420620 T1689 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:53348/rt_jpy/tu/collection1/ shard1
[junit4] 2> 420620 T1689 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 420624 T1663 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 420657 T1662 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 420660 T1662 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 420683 T1662 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 420800 T1671 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> 420800 T1684 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> 420800 T1662 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> 420816 T1689 oasc.ZkController.register We are https://127.0.0.1:53348/rt_jpy/tu/collection1/ and leader is https://127.0.0.1:53348/rt_jpy/tu/collection1/
[junit4] 2> 420816 T1689 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:53348/rt_jpy/tu
[junit4] 2> 420817 T1689 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 420817 T1689 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 420817 T1689 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 420822 T1689 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 420827 T1662 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 420827 T1662 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 420832 T1663 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 420834 T1663 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"https://127.0.0.1:53348/rt_jpy/tu",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:53348_rt_jpy%2Ftu",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 420846 T1662 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 420963 T1684 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> 420963 T1662 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> 420963 T1671 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> 422157 T1638 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 422158 T1638 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 422165 T1638 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
[junit4] 2> 422166 T1638 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:53351
[junit4] 2> 422169 T1638 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 422169 T1638 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 422170 T1638 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1395621332540
[junit4] 2> 422170 T1638 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1395621332540/'
[junit4] 2> 422225 T1638 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1395621332540/solr.xml
[junit4] 2> 422251 T1638 oasc.CoreContainer.<init> New CoreContainer 1218720446
[junit4] 2> 422251 T1638 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1395621332540/]
[junit4] 2> 422251 T1638 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 422251 T1638 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 422252 T1638 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 422252 T1638 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 422252 T1638 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 422252 T1638 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 422253 T1638 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 422253 T1638 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 422253 T1638 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 422258 T1638 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 422259 T1638 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 422259 T1638 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 422259 T1638 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53340/solr
[junit4] 2> 422259 T1638 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 422270 T1638 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 422278 T1700 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15812ac3 name:ZooKeeperConnection Watcher:127.0.0.1:53340 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 422279 T1638 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 422286 T1638 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 422289 T1702 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4e56516f name:ZooKeeperConnection Watcher:127.0.0.1:53340/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 422290 T1638 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 422304 T1638 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 423318 T1638 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53351_rt_jpy%2Ftu
[junit4] 2> 423321 T1638 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53351_rt_jpy%2Ftu
[junit4] 2> 423329 T1702 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 423333 T1671 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 423333 T1662 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 423335 T1684 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 423346 T1703 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 423346 T1703 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 423348 T1703 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 423349 T1662 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 423349 T1662 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 423349 T1662 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 423353 T1663 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 423354 T1663 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"https://127.0.0.1:53351/rt_jpy/tu",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:53351_rt_jpy%2Ftu",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 423354 T1663 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4] 2> 423354 T1663 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 423361 T1662 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 423364 T1702 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> 423365 T1671 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> 423366 T1684 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> 423366 T1662 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> 424350 T1703 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 424350 T1703 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1395621332540/collection1
[junit4] 2> 424351 T1703 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 424352 T1703 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 424353 T1703 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 424354 T1703 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 424355 T1703 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1395621332540/collection1/'
[junit4] 2> 424356 T1703 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1395621332540/collection1/lib/.svn/' to classloader
[junit4] 2> 424357 T1703 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1395621332540/collection1/lib/classes/' to classloader
[junit4] 2> 424358 T1703 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1395621332540/collection1/lib/README' to classloader
[junit4] 2> 424424 T1703 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
[junit4] 2> 424461 T1703 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 424464 T1703 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 424472 T1703 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 424739 T1703 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 424742 T1703 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 424742 T1703 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 424751 T1703 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 424819 T1703 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 424819 T1703 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1395621332540/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1395621324665/jetty2/
[junit4] 2> 424819 T1703 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@cb4b3e
[junit4] 2> 424820 T1703 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1395621324665/jetty2
[junit4] 2> 424821 T1703 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1395621324665/jetty2/index/
[junit4] 2> 424821 T1703 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1395621324665/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 424821 T1703 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1395621324665/jetty2/index
[junit4] 2> 424822 T1703 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=13, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.37212807856479335]
[junit4] 2> 424822 T1703 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@7ad30bd0 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@204f8a12),segFN=segments_1,generation=1}
[junit4] 2> 424822 T1703 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 424830 T1703 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 424830 T1703 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 424830 T1703 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 424831 T1703 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 424831 T1703 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 424832 T1703 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 424833 T1703 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 424836 T1703 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 424836 T1703 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 424837 T1703 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 424839 T1703 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 424839 T1703 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 424839 T1703 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 424840 T1703 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 424840 T1703 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 424841 T1703 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 424850 T1703 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 424854 T1703 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 424854 T1703 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 424856 T1703 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=17.1318359375, floorSegmentMB=1.5439453125, forceMergeDeletesPctAllowed=11.826569833384498, segmentsPerTier=14.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 424857 T1703 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@7ad30bd0 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@204f8a12),segFN=segments_1,generation=1}
[junit4] 2> 424858 T1703 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 424858 T1703 oass.SolrIndexSearcher.<init> Opening Searcher@32a18d4f[collection1] main
[junit4] 2> 424862 T1704 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@32a18d4f[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 424865 T1703 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 424868 T1638 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 424869 T1638 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 424868 T1707 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:53351/rt_jpy/tu collection:collection1 shard:shard1
[junit4] 2> 424872 T1638 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 424884 T1707 oasc.ZkController.register We are https://127.0.0.1:53351/rt_jpy/tu/collection1/ and leader is https://127.0.0.1:53348/rt_jpy/tu/collection1/
[junit4] 2> 424885 T1707 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:53351/rt_jpy/tu
[junit4] 2> 424885 T1707 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 424885 T1707 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C602 name=collection1 org.apache.solr.core.SolrCore@5ee70201 url=https://127.0.0.1:53351/rt_jpy/tu/collection1 node=127.0.0.1:53351_rt_jpy%2Ftu C602_STATE=coll:collection1 core:collection1 props:{state=down, base_url=https://127.0.0.1:53351/rt_jpy/tu, core=collection1, node_name=127.0.0.1:53351_rt_jpy%2Ftu}
[junit4] 2> 424886 T1710 C602 P53351 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 424886 T1710 C602 P53351 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 424887 T1710 C602 P53351 oasc.ZkController.publish publishing core=collection1 state=recovering collection=collection1
[junit4] 2> 424887 T1710 C602 P53351 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 424889 T1707 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 424894 T1662 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 424900 T1663 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 424906 T1663 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"recovering",
[junit4] 2> "base_url":"https://127.0.0.1:53351/rt_jpy/tu",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:53351_rt_jpy%2Ftu",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 424951 T1662 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 424958 T1702 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> 424959 T1662 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> 424966 T1684 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> 424966 T1671 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> 425034 T1676 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 425037 T1676 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 425039 T1676 oasha.CoreAdminHandler.handleWaitForStateAction Will wait a max of 183 seconds to see collection1 (shard1 of collection1) have state: recovering
[junit4] 2> 425039 T1676 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true for: 0 seconds.
[junit4] 2> 425039 T1676 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={nodeName=127.0.0.1:53351_rt_jpy%252Ftu&onlyIfLeaderActive=true&core=collection1&coreNodeName=core_node2&action=PREPRECOVERY&checkLive=true&state=recovering&onlyIfLeader=true&wt=javabin&version=2} status=0 QTime=5
[junit4] 2> ASYNC NEW_CORE C603 name=collection1 org.apache.solr.core.SolrCore@ee99e9d url=https://127.0.0.1:53344/rt_jpy/tu/collection1 node=127.0.0.1:53344_rt_jpy%2Ftu C603_STATE=coll:control_collection core:collection1 props:{state=active, base_url=https://127.0.0.1:53344/rt_jpy/tu, core=collection1, node_name=127.0.0.1:53344_rt_jpy%2Ftu, leader=true}
[junit4] 2> 425051 T1653 C603 P53344 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={wt=javabin&version=2&CONTROL=TRUE} {add=[1-0 (1463415039090229248)]} 0 5
[junit4] 2> 425058 T1655 C603 P53344 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={wt=javabin&version=2&CONTROL=TRUE} {add=[2-0 (1463415039099666432)]} 0 2
[junit4] 2> 425096 T1638 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 53351
[junit4] 2> 425108 T1638 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1218720446
[junit4] 2> 425109 T1638 oasc.RecoveryStrategy.close WARN Stopping recovery for zkNodeName=core_node2core=collection1
[junit4] 2> C602_STATE=coll:collection1 core:collection1 props:{state=recovering, base_url=https://127.0.0.1:53351/rt_jpy/tu, core=collection1, node_name=127.0.0.1:53351_rt_jpy%2Ftu}
[junit4] 2> 425275 T1698 C602 P53351 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:53348/rt_jpy/tu/collection1/&wt=javabin&version=2} {add=[1-0 (1463415039196135424)]} 0 6
[junit4] 2> ASYNC NEW_CORE C604 name=collection1 org.apache.solr.core.SolrCore@43c9c099 url=https://127.0.0.1:53348/rt_jpy/tu/collection1 node=127.0.0.1:53348_rt_jpy%2Ftu C604_STATE=coll:collection1 core:collection1 props:{state=active, base_url=https://127.0.0.1:53348/rt_jpy/tu, core=collection1, node_name=127.0.0.1:53348_rt_jpy%2Ftu, leader=true}
[junit4] 2> 425278 T1676 C604 P53348 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={wt=javabin&version=2} {add=[1-0 (1463415039196135424)]} 0 131
[junit4] 2> 425280 T1693 C602 P53351 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:53348/rt_jpy/tu/collection1/&wt=javabin&version=2} {add=[2-0 (1463415039194038272)]} 0 0
[junit4] 2> 425283 T1675 C604 P53348 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={wt=javabin&version=2} {add=[2-0 (1463415039194038272)]} 0 138
[junit4] 2> 425387 T1654 C603 P53344 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={wt=javabin&version=2&CONTROL=TRUE} {delete=[2-0 (-1463415039446745089)]} 0 1
[junit4] 2> 425387 T1656 C603 P53344 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={wt=javabin&version=2&CONTROL=TRUE} {delete=[1-0 (-1463415039446745088)]} 0 1
[junit4] 2> 425429 T1695 C602 P53351 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:53348/rt_jpy/tu/collection1/&wt=javabin&version=2} {delete=[1-0 (-1463415039457230848)]} 0 2
[junit4] 2> 425430 T1694 C602 P53351 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:53348/rt_jpy/tu/collection1/&wt=javabin&version=2} {delete=[2-0 (-1463415039457230849)]} 0 3
[junit4] 2> 425431 T1679 C604 P53348 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={wt=javabin&version=2} {delete=[1-0 (-1463415039457230848)]} 0 36
[junit4] 2> 425433 T1678 C604 P53348 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={wt=javabin&version=2} {delete=[2-0 (-1463415039457230849)]} 0 37
[junit4] 2> 425438 T1657 C603 P53344 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={wt=javabin&version=2&CONTROL=TRUE} {add=[1-1 (1463415039500222464)]} 0 1
[junit4] 2> 425441 T1653 C603 P53344 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={wt=javabin&version=2&CONTROL=TRUE} {add=[2-1 (1463415039504416768)]} 0 1
[junit4] 2> 425473 T1697 C602 P53351 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:53348/rt_jpy/tu/collection1/&wt=javabin&version=2} {add=[1-1 (1463415039510708224)]} 0 1
[junit4] 2> 425475 T1680 C604 P53348 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={wt=javabin&version=2} {add=[1-1 (1463415039510708224)]} 0 29
[junit4] 2> 425476 T1698 C602 P53351 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:53348/rt_jpy/tu/collection1/&wt=javabin&version=2} {add=[2-1 (1463415039528534016)]} 0 1
[junit4] 2> 425488 T1676 C604 P53348 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={wt=javabin&version=2} {add=[2-1 (1463415039528534016)]} 0 24
[junit4] 2> 425536 T1655 C603 P53344 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={wt=javabin&version=2&CONTROL=TRUE} {add=[1-2 (1463415039602982912)]} 0 0
[junit4] 2> 425546 T1693 C602 P53351 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:53348/rt_jpy/tu/collection1/&wt=javabin&version=2} {add=[1-2 (1463415039609274368)]} 0 1
[junit4] 2> 425549 T1658 C603 P53344 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={wt=javabin&version=2&CONTROL=TRUE} {add=[2-2 (1463415039616614400)]} 0 1
[junit4] 2> 425549 T1677 C604 P53348 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={wt=javabin&version=2} {add=[1-2 (1463415039609274368)]} 0 9
[junit4] 2> 425558 T1696 C602 P53351 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:53348/rt_jpy/tu/collection1/&wt=javabin&version=2} {add=[2-2 (1463415039622905856)]} 0 1
[junit4] 2> 425559 T1675 C604 P53348 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={wt=javabin&version=2} {add=[2-2 (1463415039622905856)]} 0 6
[junit4] 2> 425609 T1654 C603 P53344 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={wt=javabin&version=2&CONTROL=TRUE} {delete=[1-1 (-1463415039680577536)]} 0 1
[junit4] 2> 425627 T1656 C603 P53344 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={wt=javabin&version=2&CONTROL=TRUE} {delete=[2-1 (-1463415039698403328)]} 0 1
[junit4] 2> 425630 T1695 C602 P53351 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:53348/rt_jpy/tu/collection1/&wt=javabin&version=2} {delete=[1-1 (-1463415039686868992)]} 0 1
[junit4] 2> 425634 T1679 C604 P53348 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={wt=javabin&version=2} {delete=[1-1 (-1463415039686868992)]} 0 19
[junit4] 2> 425636 T1694 C602 P53351 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:53348/rt_jpy/tu/collection1/&wt=javabin&version=2} {delete=[2-1 (-1463415039705743360)]} 0 0
[junit4] 2> 425638 T1678 C604 P53348 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={wt=javabin&version=2} {delete=[2-1 (-1463415039705743360)]} 0 5
[junit4] 2> 425643 T1657 C603 P53344 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={wt=javabin&version=2&CONTROL=TRUE} {add=[1-3 (1463415039715180544)]} 0 1
[junit4] 2> 425645 T1653 C603 P53344 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={wt=javabin&version=2&CONTROL=TRUE} {add=[2-3 (1463415039717277696)]} 0 1
[junit4] 2> 425660 T1697 C602 P53351 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:53348/rt_jpy/tu/collection1/&wt=javabin&version=2} {add=[1-3 (1463415039722520576)]} 0 1
[junit4] 2> 425662 T1680 C604 P53348 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={wt=javabin&version=2} {add=[1-3 (1463415039722520576)]} 0 13
[junit4] 2> 425666 T1698 C602 P53351 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={update.distrib=FROMLEADER&distrib.from=https://127.0.0.1:53348/rt_jpy/tu/collection1/&wt=javabin&version=2} {add=[2-3 (1463415039730909184)]} 0 1
[junit4] 2> 425667 T1676 C604 P53348 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update params={wt=javabin&version=2} {add=[2-3 (1463415039730909184)]} 0 10
[junit4] 2> 425744 T1655 C603 P53344 oasup.LogUpdateProcessor.finish [collection1] webapp=/rt_jpy/tu path=/update par
[...truncated too long message...]
../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1395621750046/solrj_collection_shard1_replica1/data;done=false>>]
[junit4] 2> 1035654 T3443 oasc.CachingDirectoryFactory.close Closing directory: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1395621750046/solrj_collection_shard1_replica1/data
[junit4] 2> 1035654 T3581 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1035657 T3582 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1035657 T3582 oasc.OverseerCollectionProcessor.amILeader According to ZK I (id=91463466463395852-127.0.0.1:54034_t%2Fe-n_0000000004) am no longer a leader.
[junit4] 2> 1035658 T3582 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
[junit4] 2> 1035658 T3582 oasc.OverseerCollectionProcessor.run ERROR Unable to prioritize overseer java.lang.InterruptedException
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:80)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:222)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.prioritizeOverseerNodes(OverseerCollectionProcessor.java:297)
[junit4] 2> at org.apache.solr.cloud.OverseerCollectionProcessor.run(OverseerCollectionProcessor.java:211)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 1035662 T3525 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4] 2> 1035662 T3525 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1035663 T3445 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x144f189c47a000c, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:744)
[junit4] 2>
[junit4] 2> 1035676 T3443 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/t/e,null}
[junit4] 2> 1035734 T3443 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4] 2> 1035740 T3443 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:54018 54018
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=CollectionsAPIDistributedZkTest -Dtests.method=testDistribSearch -Dtests.seed=CEE5E0C435A54112 -Dtests.slow=true -Dtests.locale=el_GR -Dtests.timezone=PRC -Dtests.file.encoding=UTF-8
[junit4] ERROR 206s | CollectionsAPIDistributedZkTest.testDistribSearch <<<
[junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: deletecollection the collection time out:180s
[junit4] > at __randomizedtesting.SeedInfo.seed([CEE5E0C435A54112:4F036EDC42FA212E]:0)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:504)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:203)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:199)
[junit4] > at org.apache.solr.client.solrj.request.CollectionAdminRequest.process(CollectionAdminRequest.java:300)
[junit4] > at org.apache.solr.client.solrj.request.CollectionAdminRequest.deleteCollection(CollectionAdminRequest.java:441)
[junit4] > at org.apache.solr.client.solrj.request.CollectionAdminRequest.deleteCollection(CollectionAdminRequest.java:431)
[junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testSolrJAPICalls(CollectionsAPIDistributedZkTest.java:321)
[junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:204)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:870)
[junit4] > at java.lang.Thread.run(Thread.java:744)
[junit4] 2> 1035773 T3443 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 206081 T3442 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 5 leaked thread(s).
[junit4] 2> 1036560 T3465 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1036832 T3483 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1036832 T3483 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1036937 T3497 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1037058 T3511 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1037060 T3511 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Lucene46: {}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=el_GR, timezone=PRC
[junit4] 2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.8.0 (64-bit)/cpus=2,threads=1,free=283014208,total=490975232
[junit4] 2> NOTE: All tests run in this JVM: [CursorMarkTest, AddBlockUpdateTest, TestSolrQueryParserDefaultOperatorResource, HdfsSyncSliceTest, RequestHandlersTest, TestBadConfig, CoreAdminHandlerTest, MoreLikeThisHandlerTest, TestCollationField, AnalysisAfterCoreReloadTest, TestSolrQueryParserResource, TestFreeTextSuggestions, TestCloudManagedSchema, SliceStateUpdateTest, RAMDirectoryFactoryTest, BadCopyFieldTest, TestSolrDeletionPolicy1, CurrencyFieldXmlFileTest, SpellPossibilityIteratorTest, PreAnalyzedFieldTest, ChaosMonkeyNothingIsSafeTest, SignatureUpdateProcessorFactoryTest, DistributedSpellCheckComponentTest, ResponseLogComponentTest, TestNonNRTOpen, FieldMutatingUpdateProcessorTest, SpellingQueryConverterTest, TestValueSourceCache, TestSolrXMLSerializer, DocValuesTest, BasicZkTest, AnalysisErrorHandlingTest, HdfsUnloadDistributedZkTest, TestQuerySenderNoQuery, FullSolrCloudDistribCmdsTest, OverseerStatusTest, TestSearcherReuse, AssignTest, SuggesterFSTTest, ExternalFileFieldSortTest, SuggesterTSTTest, DocumentBuilderTest, TestSolrQueryParser, TestSolr4Spatial, TestCursorMarkWithoutUniqueKey, TestFastOutputStream, LeaderElectionIntegrationTest, EchoParamsTest, SolrInfoMBeanTest, TestGroupingSearch, SolrIndexConfigTest, StressHdfsTest, AutoCommitTest, HardAutoCommitTest, SOLR749Test, TestSolrDeletionPolicy2, TestNRTOpen, TestDocBasedVersionConstraints, TestLRUCache, TestShardHandlerFactory, TestExpandComponent, TermVectorComponentTest, TestSort, IndexSchemaTest, CoreAdminCreateDiscoverTest, IndexSchemaRuntimeFieldTest, AddSchemaFieldsUpdateProcessorFactoryTest, SimplePostToolTest, DistributedExpandComponentTest, TestRandomMergePolicy, ConvertedLegacyTest, DocValuesMultiTest, CircularListTest, CoreContainerCoreInitFailuresTest, QueryResultKeyTest, UpdateParamsTest, RecoveryZkTest, MigrateRouteKeyTest, TestSuggestSpellingConverter, TestExceedMaxTermLength, ZkCLITest, TermsComponentTest, TestSurroundQueryParser, DistributedQueryComponentOptimizationTest, ShardRoutingTest, ZkSolrClientTest, TestShortCircuitedRequests, TestReloadAndDeleteDocs, TestAtomicUpdateErrorCases, TestFiltering, CustomCollectionTest, TestWriterPerf, TestJmxMonitoredMap, TestSystemIdResolver, TestSolrXmlPersistence, DOMUtilTest, SynonymTokenizerTest, TestFastLRUCache, TestMultiCoreConfBootstrap, TermVectorComponentDistributedTest, BinaryUpdateRequestHandlerTest, TestRandomFaceting, PluginInfoTest, TestWordDelimiterFilterFactory, LoggingHandlerTest, ChangedSchemaMergeTest, TestLuceneMatchVersion, TestPseudoReturnFields, TestBM25SimilarityFactory, TestDocSet, TestCollationKeyRangeQueries, TestDynamicFieldCollectionResource, TestOverriddenPrefixQueryForCustomFieldType, WordBreakSolrSpellCheckerTest, TestPHPSerializedResponseWriter, ZkControllerTest, HdfsBasicDistributedZkTest, HdfsCollectionsAPIDistributedZkTest, TestSolrXml, TestFastWriter, CollectionsAPIDistributedZkTest]
[junit4] Completed in 207.63s, 1 test, 1 error <<< FAILURES!
[...truncated 790 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:467: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:447: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:45: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/extra-targets.xml:37: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:490: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1276: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:908: There were test failures: 378 suites, 1598 tests, 1 error, 1 failure, 42 ignored (15 assumptions)
Total time: 77 minutes 3 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.8.0 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure