You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/10/24 18:08:35 UTC
[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.6.0) - Build # 917 -
Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/917/
Java: 64bit/jdk1.6.0 -XX:-UseCompressedOops -XX:+UseParallelGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.testDistribSearch
Error Message:
shard1 is not consistent. Got 123 from http://127.0.0.1:51714/collection1lastClient and got 122 from http://127.0.0.1:51726/collection1
Stack Trace:
java.lang.AssertionError: shard1 is not consistent. Got 123 from http://127.0.0.1:51714/collection1lastClient and got 122 from http://127.0.0.1:51726/collection1
at __randomizedtesting.SeedInfo.seed([5E6BF6F08C8148A5:DF8D78E8FBDE2899]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1148)
at org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.doTest(ChaosMonkeyNothingIsSafeTest.java:194)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
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:695)
Build Log:
[...truncated 9297 lines...]
[junit4] Suite: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest
[junit4] 2> 210316 T515 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 210334 T515 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./solrtest-ChaosMonkeyNothingIsSafeTest-1382627658966
[junit4] 2> 210337 T515 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 210339 T516 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 210440 T515 oasc.ZkTestServer.run start zk server on port:51690
[junit4] 2> 210444 T515 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 210458 T522 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@713c3100 name:ZooKeeperConnection Watcher:127.0.0.1:51690 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 210459 T515 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 210460 T515 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 210491 T515 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 210518 T524 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@56fe8d80 name:ZooKeeperConnection Watcher:127.0.0.1:51690/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 210519 T515 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 210521 T515 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 210555 T515 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 210572 T515 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 210585 T515 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 210626 T515 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 210632 T515 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 210677 T515 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 210680 T515 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 210713 T515 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 210715 T515 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 210750 T515 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 210752 T515 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 210777 T515 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 210780 T515 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 210803 T515 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 210805 T515 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 210828 T515 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 210829 T515 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 210846 T515 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 210848 T515 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 210866 T515 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 210868 T515 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 210888 T515 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 210890 T515 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 211471 T515 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 211478 T515 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51693
[junit4] 2> 211485 T515 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 211486 T515 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 211487 T515 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1382627659547
[junit4] 2> 211488 T515 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1382627659547/'
[junit4] 2> 211535 T515 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1382627659547/solr.xml
[junit4] 2> 211637 T515 oasc.CoreContainer.<init> New CoreContainer 92136104
[junit4] 2> 211638 T515 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1382627659547/]
[junit4] 2> 211640 T515 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 211641 T515 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 211642 T515 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 211642 T515 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 211643 T515 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 211644 T515 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 211644 T515 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 211645 T515 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 211646 T515 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 211653 T515 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 211654 T515 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 211655 T515 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51690/solr
[junit4] 2> 211656 T515 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 211658 T515 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 211667 T535 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@bab8669 name:ZooKeeperConnection Watcher:127.0.0.1:51690 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 211669 T515 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 211684 T515 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 211690 T537 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@466001d5 name:ZooKeeperConnection Watcher:127.0.0.1:51690/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 211691 T515 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 211704 T515 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 211722 T515 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 211744 T515 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 211759 T515 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51693_
[junit4] 2> 211764 T515 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51693_
[junit4] 2> 211794 T515 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 211872 T515 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 211909 T515 oasc.Overseer.start Overseer (id=90611886258978819-127.0.0.1:51693_-n_0000000000) starting
[junit4] 2> 211949 T515 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 211983 T539 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 211988 T515 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 212018 T515 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 212038 T515 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 212079 T538 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 212087 T540 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 212088 T540 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 212100 T540 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 213605 T538 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 213608 T538 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:51693",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:51693_",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 213609 T538 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 213616 T538 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 213642 T537 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> 214102 T540 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 214103 T540 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1382627659547/collection1
[junit4] 2> 214103 T540 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 214106 T540 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 214107 T540 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 214112 T540 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1382627659547/collection1/'
[junit4] 2> 214115 T540 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1382627659547/collection1/lib/classes/' to classloader
[junit4] 2> 214117 T540 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1382627659547/collection1/lib/README' to classloader
[junit4] 2> 214196 T540 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 214268 T540 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 214274 T540 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 214290 T540 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 215048 T540 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 215049 T540 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 215051 T540 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 215078 T540 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 215085 T540 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 215177 T540 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 215187 T540 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 215199 T540 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 215205 T540 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 215206 T540 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 215206 T540 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 215213 T540 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 215213 T540 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 215214 T540 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 215255 T540 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1382627659547/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/control/data/
[junit4] 2> 215256 T540 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@58d51a54
[junit4] 2> 215257 T540 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/control/data
[junit4] 2> 215259 T540 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/control/data/index/
[junit4] 2> 215260 T540 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 215261 T540 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/control/data/index
[junit4] 2> 215262 T540 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=21, maxMergeAtOnceExplicit=16, maxMergedSegmentMB=36.6015625, floorSegmentMB=0.5830078125, forceMergeDeletesPctAllowed=13.82044021242883, segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 215269 T540 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 215270 T540 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 215279 T540 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 215280 T540 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 215280 T540 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 215281 T540 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 215281 T540 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 215282 T540 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 215283 T540 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 215283 T540 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 215284 T540 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 215285 T540 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 215286 T540 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 215286 T540 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 215287 T540 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 215288 T540 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 215289 T540 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 215299 T540 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 215304 T540 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 215305 T540 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 215306 T540 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=12, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 215310 T540 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 215311 T540 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 215312 T540 oass.SolrIndexSearcher.<init> Opening Searcher@7f8dd355 main
[junit4] 2> 215324 T541 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7f8dd355 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 215328 T540 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 215329 T540 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:51693 collection:control_collection shard:shard1
[junit4] 2> 215335 T540 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 215373 T540 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 215387 T540 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 215388 T540 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 215388 T540 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:51693/collection1/
[junit4] 2> 215389 T540 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 215390 T540 oasc.SyncStrategy.syncToMe http://127.0.0.1:51693/collection1/ has no replicas
[junit4] 2> 215390 T540 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:51693/collection1/ shard1
[junit4] 2> 215390 T540 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 216689 T538 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 216719 T537 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> 216752 T540 oasc.ZkController.register We are http://127.0.0.1:51693/collection1/ and leader is http://127.0.0.1:51693/collection1/
[junit4] 2> 216753 T540 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:51693
[junit4] 2> 216753 T540 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 216754 T540 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 216754 T540 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 216760 T540 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 216764 T515 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 216765 T515 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 216783 T515 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 216792 T544 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@210c05b5 name:ZooKeeperConnection Watcher:127.0.0.1:51690/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 216793 T515 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 216798 T515 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 216813 T515 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 217325 T515 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 217335 T515 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51697
[junit4] 2> 217340 T515 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 217341 T515 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 217342 T515 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1382627665444
[junit4] 2> 217343 T515 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1382627665444/'
[junit4] 2> 217390 T515 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1382627665444/solr.xml
[junit4] 2> 217455 T515 oasc.CoreContainer.<init> New CoreContainer 324307020
[junit4] 2> 217456 T515 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1382627665444/]
[junit4] 2> 217457 T515 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 217458 T515 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 217459 T515 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 217459 T515 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 217460 T515 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 217461 T515 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 217461 T515 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 217462 T515 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 217463 T515 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 217470 T515 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 217471 T515 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 217472 T515 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51690/solr
[junit4] 2> 217473 T515 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 217475 T515 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 217812 T555 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@12c03f7e name:ZooKeeperConnection Watcher:127.0.0.1:51690 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 217816 T515 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 217839 T515 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 217847 T557 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f7bf0a7 name:ZooKeeperConnection Watcher:127.0.0.1:51690/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 217848 T515 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 217883 T515 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 218253 T538 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 218256 T538 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:51693",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:51693_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 218276 T557 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> 218277 T544 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> 218278 T537 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> 218912 T515 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51697_
[junit4] 2> 218918 T515 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51697_
[junit4] 2> 218954 T537 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 218956 T544 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 218959 T557 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 218987 T558 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 218988 T558 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 218993 T558 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 219807 T538 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 219810 T538 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:51697",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:51697_",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 219811 T538 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 219811 T538 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 219831 T537 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> 219832 T557 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> 219832 T544 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> 219994 T558 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 219994 T558 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1382627665444/collection1
[junit4] 2> 219995 T558 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 219998 T558 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 219998 T558 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 220005 T558 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1382627665444/collection1/'
[junit4] 2> 220008 T558 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1382627665444/collection1/lib/classes/' to classloader
[junit4] 2> 220009 T558 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1382627665444/collection1/lib/README' to classloader
[junit4] 2> 220156 T558 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 220225 T558 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 220236 T558 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 220262 T558 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 221003 T558 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 221006 T558 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 221007 T558 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 221023 T558 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 221028 T558 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 221100 T558 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 221109 T558 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 221118 T558 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 221124 T558 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 221125 T558 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 221125 T558 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 221130 T558 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 221131 T558 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 221131 T558 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 221132 T558 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1382627665444/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/jetty1/
[junit4] 2> 221132 T558 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@58d51a54
[junit4] 2> 221134 T558 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/jetty1
[junit4] 2> 221136 T558 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/jetty1/index/
[junit4] 2> 221137 T558 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 221138 T558 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/jetty1/index
[junit4] 2> 221139 T558 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=21, maxMergeAtOnceExplicit=16, maxMergedSegmentMB=36.6015625, floorSegmentMB=0.5830078125, forceMergeDeletesPctAllowed=13.82044021242883, segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 221144 T558 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 221145 T558 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 221156 T558 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 221157 T558 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 221159 T558 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 221160 T558 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 221161 T558 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 221161 T558 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 221163 T558 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 221163 T558 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 221164 T558 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 221165 T558 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 221167 T558 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 221168 T558 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 221169 T558 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 221172 T558 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 221174 T558 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 221184 T558 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 221190 T558 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 221191 T558 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 221192 T558 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=12, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 221196 T558 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 221196 T558 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 221197 T558 oass.SolrIndexSearcher.<init> Opening Searcher@81d1a2 main
[junit4] 2> 221211 T559 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@81d1a2 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 221215 T558 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 221216 T558 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:51697 collection:collection1 shard:shard1
[junit4] 2> 221221 T558 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 221258 T558 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 221271 T558 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 221271 T558 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 221272 T558 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:51697/collection1/
[junit4] 2> 221273 T558 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 221273 T558 oasc.SyncStrategy.syncToMe http://127.0.0.1:51697/collection1/ has no replicas
[junit4] 2> 221274 T558 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:51697/collection1/ shard1
[junit4] 2> 221274 T558 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 221365 T538 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 221407 T537 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> 221408 T557 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> 221408 T544 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> 221466 T558 oasc.ZkController.register We are http://127.0.0.1:51697/collection1/ and leader is http://127.0.0.1:51697/collection1/
[junit4] 2> 221466 T558 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:51697
[junit4] 2> 221467 T558 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 221467 T558 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 221468 T558 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 221475 T558 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 221480 T515 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 221481 T515 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 221934 T515 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 221941 T515 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51700
[junit4] 2> 221945 T515 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 221946 T515 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 221946 T515 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1382627670114
[junit4] 2> 221947 T515 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1382627670114/'
[junit4] 2> 222007 T515 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1382627670114/solr.xml
[junit4] 2> 222072 T515 oasc.CoreContainer.<init> New CoreContainer 1982632907
[junit4] 2> 222073 T515 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1382627670114/]
[junit4] 2> 222076 T515 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 222076 T515 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 222077 T515 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 222078 T515 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 222078 T515 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 222079 T515 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 222079 T515 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 222080 T515 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 222081 T515 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 222086 T515 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 222087 T515 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 222088 T515 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51690/solr
[junit4] 2> 222089 T515 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 222091 T515 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 222100 T571 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@689b3109 name:ZooKeeperConnection Watcher:127.0.0.1:51690 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 222102 T515 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 222116 T515 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 222122 T573 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@63b6f0eb name:ZooKeeperConnection Watcher:127.0.0.1:51690/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 222123 T515 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 222149 T515 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 222948 T538 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 222953 T538 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:51697",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:51697_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 222984 T537 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> 222985 T557 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> 222987 T573 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> 222988 T544 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> 223172 T515 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51700_
[junit4] 2> 223177 T515 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51700_
[junit4] 2> 223202 T573 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 223205 T544 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 223207 T537 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 223210 T557 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 223238 T574 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 223238 T574 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 223243 T574 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 224521 T538 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 224524 T538 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:51700",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:51700_",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 224525 T538 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 224525 T538 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 224543 T537 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> 224544 T544 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> 224545 T557 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> 224547 T573 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> 225246 T574 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 225247 T574 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1382627670114/collection1
[junit4] 2> 225248 T574 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 225251 T574 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 225252 T574 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 225258 T574 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1382627670114/collection1/'
[junit4] 2> 225260 T574 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1382627670114/collection1/lib/classes/' to classloader
[junit4] 2> 225261 T574 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1382627670114/collection1/lib/README' to classloader
[junit4] 2> 225366 T574 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 225460 T574 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 225470 T574 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 225496 T574 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 226574 T574 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 226576 T574 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 226578 T574 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 226602 T574 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 226610 T574 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 226722 T574 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 226739 T574 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 226758 T574 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 226775 T574 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 226776 T574 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 226777 T574 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 226783 T574 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 226783 T574 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 226784 T574 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 226785 T574 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1382627670114/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/jetty2/
[junit4] 2> 226785 T574 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@58d51a54
[junit4] 2> 226789 T574 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/jetty2
[junit4] 2> 226790 T574 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/jetty2/index/
[junit4] 2> 226790 T574 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 226791 T574 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/jetty2/index
[junit4] 2> 226792 T574 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=21, maxMergeAtOnceExplicit=16, maxMergedSegmentMB=36.6015625, floorSegmentMB=0.5830078125, forceMergeDeletesPctAllowed=13.82044021242883, segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 226797 T574 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 226798 T574 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 226820 T574 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 226822 T574 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 226823 T574 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 226824 T574 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 226825 T574 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 226825 T574 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 226827 T574 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 226828 T574 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 226829 T574 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 226831 T574 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 226833 T574 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 226836 T574 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 226837 T574 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 226840 T574 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 226841 T574 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 226855 T574 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 226863 T574 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 226864 T574 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 226866 T574 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=12, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 226870 T574 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 226872 T574 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 226873 T574 oass.SolrIndexSearcher.<init> Opening Searcher@72b13748 main
[junit4] 2> 227895 T575 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@72b13748 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 227897 T574 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 227898 T574 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:51700 collection:collection1 shard:shard2
[junit4] 2> 227902 T574 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 227934 T574 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 227947 T574 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 227947 T574 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 227948 T574 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:51700/collection1/
[junit4] 2> 227948 T574 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 227949 T574 oasc.SyncStrategy.syncToMe http://127.0.0.1:51700/collection1/ has no replicas
[junit4] 2> 227949 T574 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:51700/collection1/ shard2
[junit4] 2> 227950 T574 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 229405 T538 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 229453 T537 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> 229455 T557 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> 229456 T544 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> 229460 T573 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> 229478 T574 oasc.ZkController.register We are http://127.0.0.1:51700/collection1/ and leader is http://127.0.0.1:51700/collection1/
[junit4] 2> 229479 T574 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:51700
[junit4] 2> 229480 T574 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 229480 T574 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 229481 T574 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 229490 T574 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 229496 T515 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 229497 T515 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 230068 T515 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 230075 T515 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51703
[junit4] 2> 230078 T515 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 230078 T515 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 230079 T515 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1382627678130
[junit4] 2> 230080 T515 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1382627678130/'
[junit4] 2> 230134 T515 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1382627678130/solr.xml
[junit4] 2> 230208 T515 oasc.CoreContainer.<init> New CoreContainer 1509658081
[junit4] 2> 230210 T515 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1382627678130/]
[junit4] 2> 230213 T515 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 230214 T515 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 230214 T515 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 230215 T515 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 230216 T515 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 230217 T515 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 230218 T515 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 230219 T515 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 230220 T515 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 230226 T515 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 230227 T515 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 230228 T515 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:51690/solr
[junit4] 2> 230229 T515 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 230232 T515 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 230239 T587 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@121fdcee name:ZooKeeperConnection Watcher:127.0.0.1:51690 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 230240 T515 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 230254 T515 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 230261 T589 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@650e2859 name:ZooKeeperConnection Watcher:127.0.0.1:51690/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 230262 T515 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 230292 T515 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 230993 T538 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 230996 T538 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:51700",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:51700_",
[junit4] 2> "shard":"shard2",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 231015 T544 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> 231016 T557 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> 231017 T589 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> 231016 T537 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> 231020 T573 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> 231315 T515 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51703_
[junit4] 2> 231320 T515 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51703_
[junit4] 2> 231339 T573 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 231341 T589 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 231342 T557 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 231345 T537 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 231346 T544 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 231369 T590 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 231369 T590 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 231374 T590 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 232556 T538 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 232560 T538 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:51703",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:51703_",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"2",
[junit4] 2> "core_node_name":"core_node3"}
[junit4] 2> 232560 T538 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 232561 T538 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 232583 T537 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> 232585 T557 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> 232586 T544 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> 232587 T573 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> 232586 T589 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> 233377 T590 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 233377 T590 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1382627678130/collection1
[junit4] 2> 233378 T590 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 233381 T590 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 233382 T590 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 233388 T590 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1382627678130/collection1/'
[junit4] 2> 233390 T590 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1382627678130/collection1/lib/classes/' to classloader
[junit4] 2> 233391 T590 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1382627678130/collection1/lib/README' to classloader
[junit4] 2> 233504 T590 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 233564 T590 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 233575 T590 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 233587 T590 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 234308 T590 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 234309 T590 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 234311 T590 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 234327 T590 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 234334 T590 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 234410 T590 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 234421 T590 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 234434 T590 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 234441 T590 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 234442 T590 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 234443 T590 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 234449 T590 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 234450 T590 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 234451 T590 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 234451 T590 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1382627678130/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/jetty3/
[junit4] 2> 234452 T590 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@58d51a54
[junit4] 2> 234454 T590 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/jetty3
[junit4] 2> 234455 T590 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/jetty3/index/
[junit4] 2> 234456 T590 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 234457 T590 oasc.CachingDirectoryFactory.get return new directory for /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/jetty3/index
[junit4] 2> 234458 T590 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=21, maxMergeAtOnceExplicit=16, maxMergedSegmentMB=36.6015625, floorSegmentMB=0.5830078125, forceMergeDeletesPctAllowed=13.82044021242883, segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 234464 T590 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/jetty3/index,segFN=segments_1,generation=1}
[junit4] 2> 234465 T590 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 234475 T590 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 234476 T590 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 234477 T590 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 234478 T590 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 234478 T590 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 234479 T590 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 234480 T590 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 234481 T590 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 234481 T590 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 234485 T590 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 234487 T590 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 234487 T590 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 234488 T590 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 234491 T590 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 234492 T590 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 234502 T590 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 234508 T590 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 234509 T590 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 234511 T590 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=12, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 234514 T590 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1382627658965/jetty3/index,segFN=segments_1,generation=1}
[junit4] 2> 234515 T590 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 234516 T590 oass.SolrIndexSearcher.<init> Opening Searcher@3b3b23d6 main
[junit4] 2> 234529 T591 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3b3b23d6 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 234535 T590 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 234535 T590 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:51703 collection:collection1 shard:shard1
[junit4] 2> 234555 T590 oasc.ZkController.register We are http://127.0.0.1:51703/collection1/ and leader is http://127.0.0.1:51697/collection1/
[junit4] 2> 234556 T590 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:51703
[junit4] 2> 234557 T590 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 234557 T590 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C55 name=collection1 org.apache.solr.core.SolrCore@3b87b8e4 url=http://127.0.0.1:51703/collection1 node=127.0.0.1:51703_ C55_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:51703, core=collection1, node_name=127.0.0.1:51703_}
[junit4] 2> 234566 T592 C55 P51703 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 234569 T592 C55 P51703 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 234570 T592 C55 P51703 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 234571 T592 C55 P51703 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 234571 T590 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 234598 T515 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
[junit4] 2> 234599 T515 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 234620 T553 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 235116 T515 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 235125 T515 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:51707
[junit4] 2> 235126 T515 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 235126 T515 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 235127 T515 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty4-1382627683233
[junit4] 2> 235128 T515 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty4-1382627683233/'
[junit4] 2> 235189 T515 oasc.ConfigSolr.fromFile Loading container configuration from /Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTes
[...truncated too long message...]
t4] 1> "base_url":"http://127.0.0.1:51721",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:51721_"}}}},
[junit4] 1> "maxShardsPerNode":"1",
[junit4] 1> "router":{"name":"compositeId"},
[junit4] 1> "replicationFactor":"1"},
[junit4] 1> "control_collection":{
[junit4] 1> "shards":{"shard1":{
[junit4] 1> "range":"80000000-7fffffff",
[junit4] 1> "state":"active",
[junit4] 1> "replicas":{"core_node1":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:51693",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:51693_",
[junit4] 1> "leader":"true"}}}},
[junit4] 1> "maxShardsPerNode":"1",
[junit4] 1> "router":{"name":"compositeId"},
[junit4] 1> "replicationFactor":"1"}}
[junit4] 1> /solr/aliases.json (0)
[junit4] 1> /solr/live_nodes (8)
[junit4] 1> /solr/live_nodes/127.0.0.1:51697_ (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:51726_ (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:51693_ (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:51703_ (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:51714_ (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:51707_ (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:51721_ (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:51700_ (0)
[junit4] 1> /solr/overseer (3)
[junit4] 1> DATA:
[junit4] 1>
[junit4] 1> /solr/overseer/queue (0)
[junit4] 1> /solr/overseer/queue-work (0)
[junit4] 1> /solr/overseer/collection-queue-work (0)
[junit4] 1> /solr/collections (2)
[junit4] 1> /solr/collections/collection1 (3)
[junit4] 1> DATA:
[junit4] 1> {"configName":"conf1"}
[junit4] 1> /solr/collections/collection1/shards (0)
[junit4] 1> /solr/collections/collection1/leader_elect (2)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1 (1)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election (4)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/90611886258978830-core_node5-n_0000000002 (0)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/90611886258978834-core_node7-n_0000000003 (0)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/90611886258978826-core_node3-n_0000000001 (0)
[junit4] 1> /solr/collections/collection1/leader_elect/shard1/election/90611886258978822-core_node1-n_0000000000 (0)
[junit4] 1> /solr/collections/collection1/leader_elect/shard2 (1)
[junit4] 1> /solr/collections/collection1/leader_elect/shard2/election (3)
[junit4] 1> /solr/collections/collection1/leader_elect/shard2/election/90611886258978832-core_node6-n_0000000002 (0)
[junit4] 1> /solr/collections/collection1/leader_elect/shard2/election/90611886258978824-core_node2-n_0000000000 (0)
[junit4] 1> /solr/collections/collection1/leader_elect/shard2/election/90611886258978828-core_node4-n_0000000001 (0)
[junit4] 1> /solr/collections/collection1/leaders (2)
[junit4] 1> /solr/collections/collection1/leaders/shard1 (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:51697_",
[junit4] 1> "base_url":"http://127.0.0.1:51697"}
[junit4] 1> /solr/collections/collection1/leaders/shard2 (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:51700_",
[junit4] 1> "base_url":"http://127.0.0.1:51700"}
[junit4] 1> /solr/collections/control_collection (3)
[junit4] 1> DATA:
[junit4] 1> {"configName":"conf1"}
[junit4] 1> /solr/collections/control_collection/shards (0)
[junit4] 1> /solr/collections/control_collection/leader_elect (1)
[junit4] 1> /solr/collections/control_collection/leader_elect/shard1 (1)
[junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election (1)
[junit4] 1> /solr/collections/control_collection/leader_elect/shard1/election/90611886258978819-core_node1-n_0000000000 (0)
[junit4] 1> /solr/collections/control_collection/leaders (1)
[junit4] 1> /solr/collections/control_collection/leaders/shard1 (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:51693_",
[junit4] 1> "base_url":"http://127.0.0.1:51693"}
[junit4] 1> /solr/overseer_elect (2)
[junit4] 1> /solr/overseer_elect/election (8)
[junit4] 1> /solr/overseer_elect/election/90611886258978819-127.0.0.1:51693_-n_0000000000 (0)
[junit4] 1> /solr/overseer_elect/election/90611886258978834-127.0.0.1:51726_-n_0000000007 (0)
[junit4] 1> /solr/overseer_elect/election/90611886258978830-127.0.0.1:51714_-n_0000000005 (0)
[junit4] 1> /solr/overseer_elect/election/90611886258978832-127.0.0.1:51721_-n_0000000006 (0)
[junit4] 1> /solr/overseer_elect/election/90611886258978828-127.0.0.1:51707_-n_0000000004 (0)
[junit4] 1> /solr/overseer_elect/election/90611886258978826-127.0.0.1:51703_-n_0000000003 (0)
[junit4] 1> /solr/overseer_elect/election/90611886258978822-127.0.0.1:51697_-n_0000000001 (0)
[junit4] 1> /solr/overseer_elect/election/90611886258978824-127.0.0.1:51700_-n_0000000002 (0)
[junit4] 1> /solr/overseer_elect/leader (0)
[junit4] 1> DATA:
[junit4] 1> {"id":"90611886258978819-127.0.0.1:51693_-n_0000000000"}
[junit4] 1> /zookeeper (1)
[junit4] 1> DATA:
[junit4] 1>
[junit4] 1>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeyNothingIsSafeTest -Dtests.method=testDistribSearch -Dtests.seed=5E6BF6F08C8148A5 -Dtests.slow=true -Dtests.locale=ko -Dtests.timezone=W-SU -Dtests.file.encoding=UTF-8
[junit4] FAILURE 100s | ChaosMonkeyNothingIsSafeTest.testDistribSearch <<<
[junit4] > Throwable #1: java.lang.AssertionError: shard1 is not consistent. Got 123 from http://127.0.0.1:51714/collection1lastClient and got 122 from http://127.0.0.1:51726/collection1
[junit4] > at __randomizedtesting.SeedInfo.seed([5E6BF6F08C8148A5:DF8D78E8FBDE2899]:0)
[junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1148)
[junit4] > at org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.doTest(ChaosMonkeyNothingIsSafeTest.java:194)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4] > at java.lang.Thread.run(Thread.java:695)
[junit4] 2> 310688 T515 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 100383 T514 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
[junit4] 2> 310743 T642 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 311927 T660 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Lucene41, sim=DefaultSimilarity, locale=ko, timezone=W-SU
[junit4] 2> NOTE: Mac OS X 10.8.5 x86_64/Apple Inc. 1.6.0_65 (64-bit)/cpus=2,threads=3,free=75105800,total=312672256
[junit4] 2> NOTE: All tests run in this JVM: [TestStressLucene, SpellCheckCollatorTest, TestCSVLoader, DocValuesTest, HdfsBasicDistributedZk2Test, DistributedQueryElevationComponentTest, ClusterStateUpdateTest, TestFieldCollectionResource, SuggesterTest, SliceStateUpdateTest, SystemInfoHandlerTest, TestQueryTypes, AddBlockUpdateTest, TestSolrDeletionPolicy1, TestFieldResource, TestRandomMergePolicy, TermVectorComponentTest, SuggesterTSTTest, SolrCmdDistributorTest, SimplePostToolTest, TestLuceneMatchVersion, CurrencyFieldOpenExchangeTest, SolrRequestParserTest, TermVectorComponentDistributedTest, TestLMDirichletSimilarityFactory, TestCollationKeyRangeQueries, TestRTGBase, ScriptEngineTest, TestIBSimilarityFactory, BlockDirectoryTest, ChaosMonkeyNothingIsSafeTest]
[junit4] Completed in 101.71s, 1 test, 1 failure <<< FAILURES!
[...truncated 927 lines...]
BUILD FAILED
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:428: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:408: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build.xml:189: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/common-build.xml:483: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:1263: The following error occurred while executing this line:
/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/lucene/common-build.xml:906: There were test failures: 328 suites, 1455 tests, 1 failure, 40 ignored (5 assumptions)
Total time: 102 minutes 11 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.6.0 -XX:-UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure