You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/08/17 00:45:00 UTC
[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.7.0) - Build # 738 -
Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/738/
Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseSerialGC
2 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.testDistribSearch
Error Message:
No live SolrServers available to handle this request:[http://127.0.0.1:49988/collection1, http://127.0.0.1:49985/collection1, http://127.0.0.1:49982/collection1]
Stack Trace:
org.apache.solr.client.solrj.SolrServerException: No live SolrServers available to handle this request:[http://127.0.0.1:49988/collection1, http://127.0.0.1:49985/collection1, http://127.0.0.1:49982/collection1]
at __randomizedtesting.SeedInfo.seed([1B3EF5FF2AA5AD8F:9AD87BE75DFACDB3]:0)
at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:333)
at org.apache.solr.client.solrj.impl.CloudSolrServer.request(CloudSolrServer.java:318)
at org.apache.solr.client.solrj.request.QueryRequest.process(QueryRequest.java:90)
at org.apache.solr.client.solrj.SolrServer.query(SolrServer.java:301)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1138)
at org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.doTest(ChaosMonkeySafeLeaderTest.java:137)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Caused by: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:49982/collection1 returned non ok status:500, message:Server Error
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.client.solrj.impl.LBHttpSolrServer.request(LBHttpSolrServer.java:264)
... 46 more
REGRESSION: org.apache.solr.cloud.CollectionsAPIDistributedZkTest.testDistribSearch
Error Message:
Server at http://127.0.0.1:50924 returned non ok status:500, message:Server Error
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:50924 returned non ok status:500, message:Server Error
at __randomizedtesting.SeedInfo.seed([1B3EF5FF2AA5AD8F:9AD87BE75DFACDB3]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.deletePartiallyCreatedCollection(CollectionsAPIDistributedZkTest.java:227)
at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:154)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Build Log:
[...truncated 9808 lines...]
[junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
[junit4] 2> 1988890 T2687 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 1988902 T2687 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-ChaosMonkeySafeLeaderTest-1376690740312
[junit4] 2> 1988904 T2687 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 1988905 T2688 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 1989006 T2687 oasc.ZkTestServer.run start zk server on port:49975
[junit4] 2> 1989011 T2687 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1989023 T2694 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@bf4ae99 name:ZooKeeperConnection Watcher:127.0.0.1:49975 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1989023 T2687 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1989024 T2687 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 1989038 T2687 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1989045 T2696 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6c54d683 name:ZooKeeperConnection Watcher:127.0.0.1:49975/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1989046 T2687 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1989046 T2687 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 1989055 T2687 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 1989062 T2687 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 1989067 T2687 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 1989074 T2687 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 1989075 T2687 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 1989092 T2687 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 1989093 T2687 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 1989099 T2687 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1989100 T2687 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 1989108 T2687 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 1989109 T2687 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 1989116 T2687 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 1989117 T2687 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 1989124 T2687 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 1989125 T2687 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 1989132 T2687 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 1989133 T2687 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 1989140 T2687 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1989141 T2687 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 1989149 T2687 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 1989150 T2687 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 1989162 T2687 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 1989164 T2687 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 1989649 T2687 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1989661 T2687 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49978
[junit4] 2> 1989661 T2687 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1989662 T2687 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1989662 T2687 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1376690740582
[junit4] 2> 1989663 T2687 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1376690740582/'
[junit4] 2> 1989711 T2687 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1376690740582/solr.xml
[junit4] 2> 1989868 T2687 oasc.CoreContainer.<init> New CoreContainer 1779405958
[junit4] 2> 1989870 T2687 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1376690740582/]
[junit4] 2> 1989875 T2687 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1989876 T2687 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1989877 T2687 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1989878 T2687 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1989879 T2687 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1989880 T2687 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1989881 T2687 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1989882 T2687 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1989882 T2687 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1989883 T2687 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1989918 T2687 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49975/solr
[junit4] 2> 1989920 T2687 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1989924 T2687 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1989931 T2707 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1aecce7a name:ZooKeeperConnection Watcher:127.0.0.1:49975 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1989932 T2687 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1989946 T2687 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1989970 T2687 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1989975 T2709 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7cb72da9 name:ZooKeeperConnection Watcher:127.0.0.1:49975/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1989976 T2687 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1989981 T2687 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 1989990 T2687 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 1989999 T2687 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 1990010 T2687 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49978_
[junit4] 2> 1990013 T2687 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49978_
[junit4] 2> 1990022 T2687 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 1990035 T2687 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 1990041 T2687 oasc.Overseer.start Overseer (id=90222804357742595-127.0.0.1:49978_-n_0000000000) starting
[junit4] 2> 1990050 T2687 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 1990068 T2710 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 1990069 T2711 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 1990076 T2687 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 1990083 T2687 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 1990087 T2687 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1990106 T2712 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1990106 T2712 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1990109 T2712 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1991577 T2710 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1991578 T2710 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard":null,
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:49978_",
[junit4] 2> "base_url":"http://127.0.0.1:49978"}
[junit4] 2> 1991579 T2710 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 1991579 T2710 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1991586 T2709 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> 1992120 T2712 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1992120 T2712 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1376690740582/collection1
[junit4] 2> 1992121 T2712 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 1992123 T2712 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1992123 T2712 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 1992126 T2712 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1376690740582/collection1/'
[junit4] 2> 1992127 T2712 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1376690740582/collection1/lib/classes/' to classloader
[junit4] 2> 1992128 T2712 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1376690740582/collection1/lib/README' to classloader
[junit4] 2> 1992246 T2712 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 1992405 T2712 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1992410 T2712 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1992436 T2712 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 1993662 T2712 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 1993677 T2712 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 1993682 T2712 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 1993729 T2712 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1993743 T2712 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 1993774 T2712 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1993781 T2712 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1993786 T2712 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1993786 T2712 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 1993790 T2712 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 1993791 T2712 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 1993792 T2712 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 1993792 T2712 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1376690740582/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1376690740312/control/data/
[junit4] 2> 1993793 T2712 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@55695a74
[junit4] 2> 1993795 T2712 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1376690740312/control/data
[junit4] 2> 1993797 T2712 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1376690740312/control/data/index/
[junit4] 2> 1993798 T2712 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1376690740312/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 1993800 T2712 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1376690740312/control/data/index
[junit4] 2> 1993802 T2712 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1985221243, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 1993811 T2712 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1376690740312/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 1993812 T2712 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1993821 T2712 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 1993822 T2712 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 1993822 T2712 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 1993823 T2712 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 1993824 T2712 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 1993824 T2712 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 1993825 T2712 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1993827 T2712 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 1993828 T2712 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 1993829 T2712 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 1993832 T2712 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 1993832 T2712 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 1993833 T2712 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 1993834 T2712 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 1993835 T2712 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 1993863 T2712 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 1993873 T2712 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 1993874 T2712 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 1993875 T2712 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=39, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3936330647130979]
[junit4] 2> 1993879 T2712 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1376690740312/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 1993880 T2712 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 1993880 T2712 oass.SolrIndexSearcher.<init> Opening Searcher@21992b95 main
[junit4] 2> 1993887 T2713 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@21992b95 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 1993889 T2712 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 1993890 T2712 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49978 collection:control_collection shard:shard1
[junit4] 2> 1993890 T2712 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 1993908 T2712 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 1993934 T2712 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 1993943 T2712 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 1993944 T2712 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 1993944 T2712 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49978/collection1/
[junit4] 2> 1993945 T2712 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 1993945 T2712 oasc.SyncStrategy.syncToMe http://127.0.0.1:49978/collection1/ has no replicas
[junit4] 2> 1993946 T2712 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49978/collection1/ shard1
[junit4] 2> 1993946 T2712 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 1994606 T2710 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1994641 T2709 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> 1994688 T2712 oasc.ZkController.register We are http://127.0.0.1:49978/collection1/ and leader is http://127.0.0.1:49978/collection1/
[junit4] 2> 1994688 T2712 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49978
[junit4] 2> 1994689 T2712 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 1994689 T2712 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 1994689 T2712 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1994696 T2712 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1994700 T2687 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 1994701 T2687 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 1994702 T2687 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 1994725 T2687 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4] 2> 1994730 T2687 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1994736 T2716 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@701fb255 name:ZooKeeperConnection Watcher:127.0.0.1:49975/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1994737 T2687 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1994743 T2687 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1994753 T2687 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 1995353 T2687 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 1995358 T2687 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49982
[junit4] 2> 1995363 T2687 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 1995363 T2687 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 1995364 T2687 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1376690746163
[junit4] 2> 1995365 T2687 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1376690746163/'
[junit4] 2> 1995414 T2687 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../../Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1376690746163/solr.xml
[junit4] 2> 1995560 T2687 oasc.CoreContainer.<init> New CoreContainer 196253016
[junit4] 2> 1995561 T2687 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1376690746163/]
[junit4] 2> 1995564 T2687 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 1995564 T2687 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 1995565 T2687 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 1995565 T2687 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 1995566 T2687 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 1995566 T2687 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 1995567 T2687 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 1995567 T2687 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 1995568 T2687 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 1995568 T2687 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 1995589 T2687 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49975/solr
[junit4] 2> 1995590 T2687 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 1995592 T2687 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1995598 T2727 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@317670b7 name:ZooKeeperConnection Watcher:127.0.0.1:49975 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1995598 T2687 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1995603 T2687 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 1995626 T2687 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 1995631 T2729 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@42478ea4 name:ZooKeeperConnection Watcher:127.0.0.1:49975/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 1995631 T2687 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 1995645 T2687 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 1996172 T2710 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1996175 T2710 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "numShards":"1",
[junit4] 2> "shard":"shard1",
[junit4] 2> "roles":null,
[junit4] 2> "state":"active",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:49978_",
[junit4] 2> "base_url":"http://127.0.0.1:49978"}
[junit4] 2> 1996189 T2709 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> 1996190 T2729 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> 1996190 T2716 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> 1996662 T2687 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49982_
[junit4] 2> 1996667 T2687 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49982_
[junit4] 2> 1996686 T2716 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1996687 T2716 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1996687 T2729 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1996689 T2729 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4] 2> 1996688 T2709 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 1996698 T2709 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 1996731 T2730 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 1996732 T2730 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 1996736 T2730 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 1997714 T2710 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 1997717 T2710 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "numShards":"3",
[junit4] 2> "shard":null,
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:49982_",
[junit4] 2> "base_url":"http://127.0.0.1:49982"}
[junit4] 2> 1997718 T2710 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 1997718 T2710 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 1997737 T2709 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> 1997738 T2716 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> 1997792 T2729 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> 1998740 T2730 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 1998741 T2730 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1376690746163/collection1
[junit4] 2> 1998741 T2730 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 1998744 T2730 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 1998744 T2730 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 1998748 T2730 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1376690746163/collection1/'
[junit4] 2> 1998751 T2730 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1376690746163/collection1/lib/classes/' to classloader
[junit4] 2> 1998753 T2730 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1376690746163/collection1/lib/README' to classloader
[junit4] 2> 1998919 T2730 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 1999075 T2730 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 1999080 T2730 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 1999144 T2730 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2000739 T2730 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 2000765 T2730 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2000775 T2730 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2000844 T2730 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2000853 T2730 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2000867 T2730 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2000872 T2730 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2000873 T2730 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2000874 T2730 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2000881 T2730 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2000884 T2730 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2000887 T2730 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 2000889 T2730 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1376690746163/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1376690740312/jetty1/
[junit4] 2> 2000890 T2730 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@55695a74
[junit4] 2> 2000897 T2730 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1376690740312/jetty1
[junit4] 2> 2000898 T2730 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1376690740312/jetty1/index/
[junit4] 2> 2000899 T2730 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1376690740312/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 2000901 T2730 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1376690740312/jetty1/index
[junit4] 2> 2000903 T2730 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1985221243, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 2000911 T2730 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1376690740312/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 2000912 T2730 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2000924 T2730 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2000926 T2730 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2000927 T2730 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2000932 T2730 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2000933 T2730 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2000933 T2730 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2000933 T2730 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2000934 T2730 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2000934 T2730 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2000935 T2730 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2000937 T2730 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2000937 T2730 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2000938 T2730 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2000939 T2730 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2000940 T2730 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2000955 T2730 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2000969 T2730 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2000970 T2730 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2000971 T2730 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=39, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3936330647130979]
[junit4] 2> 2000978 T2730 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1376690740312/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 2000979 T2730 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2000980 T2730 oass.SolrIndexSearcher.<init> Opening Searcher@31743721 main
[junit4] 2> 2001010 T2731 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@31743721 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 2001017 T2730 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2001017 T2730 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49982 collection:collection1 shard:shard1
[junit4] 2> 2001018 T2730 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 2001046 T2730 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 2001104 T2730 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 2001114 T2730 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 2001115 T2730 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 2001116 T2730 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49982/collection1/
[junit4] 2> 2001116 T2730 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 2001117 T2730 oasc.SyncStrategy.syncToMe http://127.0.0.1:49982/collection1/ has no replicas
[junit4] 2> 2001117 T2730 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49982/collection1/ shard1
[junit4] 2> 2001118 T2730 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 2002310 T2710 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2002338 T2729 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> 2002338 T2709 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> 2002339 T2716 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> 2002351 T2730 oasc.ZkController.register We are http://127.0.0.1:49982/collection1/ and leader is http://127.0.0.1:49982/collection1/
[junit4] 2> 2002352 T2730 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49982
[junit4] 2> 2002353 T2730 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 2002353 T2730 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 2002354 T2730 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2002362 T2730 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2002368 T2687 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 2002369 T2687 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2002371 T2687 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 2003325 T2687 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2003356 T2687 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49985
[junit4] 2> 2003362 T2687 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2003363 T2687 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2003364 T2687 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1376690753812
[junit4] 2> 2003365 T2687 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1376690753812/'
[junit4] 2> 2003439 T2687 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1376690753812/solr.xml
[junit4] 2> 2003666 T2687 oasc.CoreContainer.<init> New CoreContainer 1696680034
[junit4] 2> 2003667 T2687 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1376690753812/]
[junit4] 2> 2003672 T2687 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 2003673 T2687 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 2003673 T2687 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2003674 T2687 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2003675 T2687 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2003675 T2687 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2003676 T2687 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2003677 T2687 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2003678 T2687 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2003682 T2687 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 2003724 T2687 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49975/solr
[junit4] 2> 2003726 T2687 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2003731 T2687 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2003746 T2743 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@60504781 name:ZooKeeperConnection Watcher:127.0.0.1:49975 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2003746 T2687 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2003766 T2687 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 2003803 T2687 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2003809 T2745 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4d3b00c name:ZooKeeperConnection Watcher:127.0.0.1:49975/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2003811 T2687 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2003832 T2687 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2003881 T2710 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2003886 T2710 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node1",
[junit4] 2> "numShards":"3",
[junit4] 2> "shard":"shard1",
[junit4] 2> "roles":null,
[junit4] 2> "state":"active",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:49982_",
[junit4] 2> "base_url":"http://127.0.0.1:49982"}
[junit4] 2> 2003905 T2745 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> 2003906 T2709 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> 2003907 T2716 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> 2003907 T2729 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> 2004854 T2687 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49985_
[junit4] 2> 2004874 T2687 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49985_
[junit4] 2> 2004887 T2745 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2004888 T2709 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4] 2> 2004894 T2729 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 2004894 T2729 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 2004895 T2716 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 2004895 T2716 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 2004908 T2709 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 2004909 T2745 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 2004940 T2746 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 2004941 T2746 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2004945 T2746 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2005428 T2710 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2005432 T2710 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "numShards":"3",
[junit4] 2> "shard":null,
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:49985_",
[junit4] 2> "base_url":"http://127.0.0.1:49985"}
[junit4] 2> 2005432 T2710 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2005432 T2710 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 2005453 T2709 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> 2005454 T2716 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> 2005454 T2729 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> 2005455 T2745 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> 2005948 T2746 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 2005949 T2746 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1376690753812/collection1
[junit4] 2> 2005949 T2746 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 2005952 T2746 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2005952 T2746 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2005956 T2746 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1376690753812/collection1/'
[junit4] 2> 2005959 T2746 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1376690753812/collection1/lib/classes/' to classloader
[junit4] 2> 2005961 T2746 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1376690753812/collection1/lib/README' to classloader
[junit4] 2> 2006096 T2746 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 2006284 T2746 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2006289 T2746 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2006325 T2746 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2008080 T2746 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 2008107 T2746 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2008117 T2746 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2008196 T2746 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2008208 T2746 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 2008234 T2746 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2008239 T2746 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2008240 T2746 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2008240 T2746 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 2008244 T2746 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 2008245 T2746 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 2008245 T2746 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 2008246 T2746 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1376690753812/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1376690740312/jetty2/
[junit4] 2> 2008246 T2746 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@55695a74
[junit4] 2> 2008248 T2746 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1376690740312/jetty2
[junit4] 2> 2008251 T2746 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1376690740312/jetty2/index/
[junit4] 2> 2008253 T2746 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1376690740312/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 2008254 T2746 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1376690740312/jetty2/index
[junit4] 2> 2008256 T2746 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=1985221243, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 2008274 T2746 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1376690740312/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 2008275 T2746 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2008286 T2746 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 2008287 T2746 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 2008287 T2746 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 2008288 T2746 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 2008288 T2746 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 2008289 T2746 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 2008290 T2746 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2008291 T2746 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 2008291 T2746 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 2008294 T2746 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 2008296 T2746 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 2008297 T2746 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 2008298 T2746 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 2008300 T2746 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 2008301 T2746 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 2008325 T2746 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 2008334 T2746 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 2008335 T2746 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 2008336 T2746 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=39, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3936330647130979]
[junit4] 2> 2008341 T2746 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1376690740312/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 2008342 T2746 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 2008342 T2746 oass.SolrIndexSearcher.<init> Opening Searcher@5e085fdd main
[junit4] 2> 2008352 T2747 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5e085fdd main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 2008357 T2746 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 2008358 T2746 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49985 collection:collection1 shard:shard2
[junit4] 2> 2008360 T2746 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=15000&socketTimeout=30000&retry=false
[junit4] 2> 2008394 T2746 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 2008438 T2746 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 2008451 T2746 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 2008451 T2746 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 2008452 T2746 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49985/collection1/
[junit4] 2> 2008452 T2746 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 2008453 T2746 oasc.SyncStrategy.syncToMe http://127.0.0.1:49985/collection1/ has no replicas
[junit4] 2> 2008454 T2746 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49985/collection1/ shard2
[junit4] 2> 2008454 T2746 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 2008508 T2710 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2008548 T2716 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> 2008549 T2729 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> 2008549 T2709 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> 2008548 T2745 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> 2008597 T2746 oasc.ZkController.register We are http://127.0.0.1:49985/collection1/ and leader is http://127.0.0.1:49985/collection1/
[junit4] 2> 2008597 T2746 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49985
[junit4] 2> 2008598 T2746 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 2008598 T2746 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 2008598 T2746 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2008604 T2746 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2008608 T2687 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 2008609 T2687 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 2008610 T2687 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4] 2> 2009343 T2687 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 2009353 T2687 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49988
[junit4] 2> 2009356 T2687 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 2009357 T2687 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 2009358 T2687 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1376690760039
[junit4] 2> 2009359 T2687 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1376690760039/'
[junit4] 2> 2009428 T2687 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1376690760039/solr.xml
[junit4] 2> 2009606 T2687 oasc.CoreContainer.<init> New CoreContainer 1733815166
[junit4] 2> 2009608 T2687 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1376690760039/]
[junit4] 2> 2009612 T2687 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 2009613 T2687 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 2009613 T2687 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 2009614 T2687 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 2009615 T2687 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 2009615 T2687 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 2009616 T2687 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 2009617 T2687 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 2009618 T2687 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 2009618 T2687 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4] 2> 2009648 T2687 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49975/solr
[junit4] 2> 2009649 T2687 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 2009652 T2687 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2009660 T2759 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10e781ad name:ZooKeeperConnection Watcher:127.0.0.1:49975 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2009660 T2687 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2009681 T2687 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4] 2> 2009704 T2687 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 2009710 T2761 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@519e16a6 name:ZooKeeperConnection Watcher:127.0.0.1:49975/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 2009711 T2687 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 2009722 T2687 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 2010088 T2710 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2010092 T2710 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node2",
[junit4] 2> "numShards":"3",
[junit4] 2> "shard":"shard2",
[junit4] 2> "roles":null,
[junit4] 2> "state":"active",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:49985_",
[junit4] 2> "base_url":"http://127.0.0.1:49985"}
[junit4] 2> 2010116 T2729 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> 2010117 T2709 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> 2010118 T2716 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> 2010119 T2761 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> 2010125 T2745 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> 2010735 T2687 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49988_
[junit4] 2> 2010739 T2687 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49988_
[junit4] 2> 2010747 T2709 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 2010751 T2745 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4] 2> 2010758 T2716 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 2010759 T2716 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4] 2> 2010760 T2761 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 2010760 T2761 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4] 2> 2010761 T2729 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 2010761 T2729 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4] 2> 2010775 T2709 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 2010794 T2745 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 2010840 T2762 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 2010841 T2762 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 2010845 T2762 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 2011648 T2710 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 2011652 T2710 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "core_node_name":"core_node3",
[junit4] 2> "numShards":"3",
[junit4] 2> "shard":null,
[junit4] 2> "roles":null,
[junit4] 2> "state":"down",
[junit4] 2> "shard_state":"active",
[junit4] 2> "core":"collection1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "shard_range":null,
[junit4] 2> "node_name":"127.0.0.1:49988_",
[junit4] 2> "base_url":"http://127.0.0.1:49988"}
[junit4] 2> 2011656 T2710 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 2011658 T2710 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 2011680 T2709 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 2011681 T2716 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 2011682 T2729 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 2011683 T2745 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 2011683 T2761 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4] 2> 2011847 T2762 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 2011848 T2762 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1376690760039/collection1
[junit4] 2> 2011849 T2762 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 2011854 T2762 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 2011855 T2762 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 2011866 T2762 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1376690760039/collection1/'
[junit4] 2> 2011870 T2762 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1376690760039/collection1/lib/classes/' to classloader
[junit4] 2> 2011871 T2762 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1376690760039/collection1/lib/README' to classloader
[junit4] 2> 2011999 T2762 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 2012176 T2762 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 2012182 T2762 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 2012212 T2762 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 2013736 T2762 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 2013762 T2762 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 2013771 T2762 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 2013818 T2762 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[...truncated too long message...]
eState ref count has reached 0 - closing IndexWriter
[junit4] 2> 2480250 T3654 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 2480251 T3654 oasc.SolrCore.closeSearcher [awholynewcollection_3_shard4_replica1] Closing main searcher on request.
[junit4] 2> 2480252 T3654 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 2480253 T3654 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1376691040542/awholynewcollection_3_shard4_replica1/data/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1376691040542/awholynewcollection_3_shard4_replica1/data/index;done=false>>]
[junit4] 2> 2480253 T3654 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1376691040542/awholynewcollection_3_shard4_replica1/data/index
[junit4] 2> 2480254 T3654 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1376691040542/awholynewcollection_3_shard4_replica1/data [CachedDir<<refCount=0;path=./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1376691040542/awholynewcollection_3_shard4_replica1/data;done=false>>]
[junit4] 2> 2480255 T3654 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.CollectionsAPIDistributedZkTest-jetty4-1376691040542/awholynewcollection_3_shard4_replica1/data
[junit4] 2> 2480257 T3962 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=90222823490584588-127.0.0.1:50933_-n_0000000004) am no longer a leader.
[junit4] 2> 2480263 T3736 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4] 2> 2480280 T3654 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4] 2> 2480342 T3654 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4] 2> 2480345 T3654 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:50917 50917
[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=1B3EF5FF2AA5AD8F -Dtests.slow=true -Dtests.locale=sr__#Latn -Dtests.timezone=Asia/Kabul -Dtests.file.encoding=US-ASCII
[junit4] ERROR 200s | CollectionsAPIDistributedZkTest.testDistribSearch <<<
[junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:50924 returned non ok status:500, message:Server Error
[junit4] > at __randomizedtesting.SeedInfo.seed([1B3EF5FF2AA5AD8F:9AD87BE75DFACDB3]:0)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
[junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.deletePartiallyCreatedCollection(CollectionsAPIDistributedZkTest.java:227)
[junit4] > at org.apache.solr.cloud.CollectionsAPIDistributedZkTest.doTest(CollectionsAPIDistributedZkTest.java:154)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4] 2> 2480476 T3654 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 199660 T3653 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4] 2> 2481565 T3736 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 2481566 T3736 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Lucene42: {timestamp=PostingsFormat(name=TestBloomFilteredLucene41Postings), range_facet_l=PostingsFormat(name=TestBloomFilteredLucene41Postings), id=PostingsFormat(name=Memory doPackFST= false), range_facet_sl=PostingsFormat(name=Memory doPackFST= false), a_t=PostingsFormat(name=TestBloomFilteredLucene41Postings), text=PostingsFormat(name=Asserting), range_facet_si=PostingsFormat(name=TestBloomFilteredLucene41Postings), _version_=PostingsFormat(name=MockRandom), other_tl1=PostingsFormat(name=MockRandom), multiDefault=PostingsFormat(name=TestBloomFilteredLucene41Postings), a_si=PostingsFormat(name=MockRandom), intDefault=PostingsFormat(name=MockRandom)}, docValues:{timestamp=DocValuesFormat(name=Disk)}, sim=DefaultSimilarity, locale=sr__#Latn, timezone=Asia/Kabul
[junit4] 2> NOTE: Mac OS X 10.8.4 x86_64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=2,threads=1,free=117793776,total=282632192
[junit4] 2> NOTE: All tests run in this JVM: [TestRandomMergePolicy, HighlighterConfigTest, SliceStateUpdateTest, TestNRTOpen, TestStressRecovery, CoreAdminHandlerTest, UnloadDistributedZkTest, TestDefaultSearchFieldResource, SignatureUpdateProcessorFactoryTest, StatelessScriptUpdateProcessorFactoryTest, TestSolrXMLSerializer, SpellCheckCollatorTest, WordBreakSolrSpellCheckerTest, DirectUpdateHandlerTest, SimplePostToolTest, HdfsBasicDistributedZkTest, SolrPluginUtilsTest, MBeansHandlerTest, ParsingFieldUpdateProcessorsTest, TestLFUCache, PreAnalyzedUpdateProcessorTest, SolrCoreCheckLockOnStartupTest, OpenExchangeRatesOrgProviderTest, TestBM25SimilarityFactory, TestSolrXml, DocValuesMultiTest, TestBadConfig, UpdateParamsTest, QueryElevationComponentTest, TestCSVResponseWriter, ShardSplitTest, PolyFieldTest, TestFoldingMultitermQuery, TestStressReorder, TestLMDirichletSimilarityFactory, RequiredFieldsTest, TestFiltering, ReturnFieldsTest, ScriptEngineTest, NoCacheHeaderTest, TestSweetSpotSimilarityFactory, TestAddFieldRealTimeGet, ChaosMonkeyNothingIsSafeTest, SchemaVersionSpecificBehaviorTest, TestXIncludeConfig, SampleTest, TestSolrQueryParserResource, ClusterStateUpdateTest, SpellPossibilityIteratorTest, TestDFRSimilarityFactory, TestIndexSearcher, StressHdfsTest, TestBinaryField, QueryResultKeyTest, TestSolrXmlPersistence, TestSolrQueryParserDefaultOperatorResource, TestSuggestSpellingConverter, TestLRUCache, TestJoin, SolrInfoMBeanTest, SolrTestCaseJ4Test, SimpleFacetsTest, TestCSVLoader, TestHashPartitioner, TestFaceting, MultiTermTest, RegexBoostProcessorTest, TestCloudManagedSchemaAddField, TestJmxIntegration, AliasIntegrationTest, LoggingHandlerTest, DirectSolrSpellCheckerTest, TestPerFieldSimilarity, PluginInfoTest, SpellCheckComponentTest, TestFieldTypeCollectionResource, TestAnalyzedSuggestions, TestJmxMonitoredMap, SolrIndexConfigTest, TestWriterPerf, TestQueryUtils, SOLR749Test, TestValueSourceCache, TestReversedWildcardFilterFactory, TestConfig, TestElisionMultitermQuery, TestCodecSupport, BadCopyFieldTest, TestStressLucene, NumericFieldsTest, TestIBSimilarityFactory, PrimitiveFieldTypeTest, CoreAdminCreateDiscoverTest, FileUtilsTest, TestAtomicUpdateErrorCases, SolrXmlInZkTest, TestSystemIdResolver, DisMaxRequestHandlerTest, SolrRequestParserTest, BasicZkTest, UUIDFieldTest, TestArbitraryIndexDir, TestInfoStreamLogging, TestDynamicFieldResource, IndexSchemaRuntimeFieldTest, TestSchemaResource, StatsComponentTest, PrimUtilsTest, TestCoreContainer, TestDocSet, NotRequiredUniqueKeyTest, FileBasedSpellCheckerTest, SuggesterFSTTest, XsltUpdateRequestHandlerTest, CurrencyFieldXmlFileTest, LegacyHTMLStripCharFilterTest, TestQuerySenderNoQuery, CacheHeaderTest, TestMaxScoreQueryParser, TestGroupingSearch, HdfsSyncSliceTest, ResourceLoaderTest, IndexBasedSpellCheckerTest, HardAutoCommitTest, TestSerializedLuceneMatchVersion, ExternalFileFieldSortTest, DistributedQueryElevationComponentTest, TestFieldResource, SpellingQueryConverterTest, TestLuceneMatchVersion, SuggesterTest, RAMDirectoryFactoryTest, FieldMutatingUpdateProcessorTest, TestFunctionQuery, ResponseLogComponentTest, TestSolrJ, FieldAnalysisRequestHandlerTest, SortByFunctionTest, SearchHandlerTest, DeleteShardTest, SolrCoreTest, TestRangeQuery, TestUpdate, ClusterStateTest, XmlUpdateRequestHandlerTest, TestBinaryResponseWriter, QueryParsingTest, TestQueryTypes, TestPhraseSuggestions, ShowFileRequestHandlerTest, DirectUpdateHandlerOptimizeTest, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test, CollectionsAPIDistributedZkTest]
[junit4] Completed in 201.01s, 1 test, 1 error <<< FAILURES!
[...truncated 492 lines...]
BUILD FAILED
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:389: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:369: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build.xml:181: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/common-build.xml:450: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1230: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:873: There were test failures: 321 suites, 1371 tests, 2 errors, 39 ignored (5 assumptions)
Total time: 116 minutes 2 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure