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/11/02 10:53:46 UTC

[JENKINS] Lucene-Solr-4.x-MacOSX (64bit/jdk1.7.0) - Build # 948 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-MacOSX/948/
Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseParallelGC

1 tests failed.
REGRESSION:  org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.testDistribSearch

Error Message:
document count mismatch.  control=27 sum(shards)=28 cloudClient=28

Stack Trace:
java.lang.AssertionError: document count mismatch.  control=27 sum(shards)=28 cloudClient=28
	at __randomizedtesting.SeedInfo.seed([A430C890F85CE620:25D646888F03861C]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1240)
	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:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:744)




Build Log:
[...truncated 10250 lines...]
   [junit4] Suite: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest
   [junit4]   2> 1171219 T2967 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /siodz/zu
   [junit4]   2> 1171227 T2967 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-1383383890684
   [junit4]   2> 1171229 T2967 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 1171230 T2968 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1171331 T2967 oasc.ZkTestServer.run start zk server on port:53573
   [junit4]   2> 1171332 T2967 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1171339 T2974 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3be57b62 name:ZooKeeperConnection Watcher:127.0.0.1:53573 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1171340 T2967 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1171340 T2967 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1171352 T2967 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1171358 T2976 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7d5b6c28 name:ZooKeeperConnection Watcher:127.0.0.1:53573/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1171358 T2967 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1171358 T2967 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 1171367 T2967 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 1171374 T2967 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 1171380 T2967 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 1171385 T2967 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> 1171386 T2967 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 1171393 T2967 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> 1171394 T2967 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 1171402 T2967 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> 1171402 T2967 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1171410 T2967 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> 1171410 T2967 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 1171418 T2967 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> 1171418 T2967 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 1171426 T2967 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> 1171427 T2967 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 1171436 T2967 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> 1171436 T2967 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1171444 T2967 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> 1171445 T2967 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1171453 T2967 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> 1171454 T2967 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 1171462 T2967 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> 1171463 T2967 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 1171769 T2967 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1171784 T2967 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53576
   [junit4]   2> 1171785 T2967 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1171785 T2967 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1171786 T2967 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383383890928
   [junit4]   2> 1171786 T2967 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383383890928/'
   [junit4]   2> 1171813 T2967 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-controljetty-1383383890928/solr.xml
   [junit4]   2> 1171877 T2967 oasc.CoreContainer.<init> New CoreContainer 967479335
   [junit4]   2> 1171877 T2967 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383383890928/]
   [junit4]   2> 1171878 T2967 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 240000
   [junit4]   2> 1171879 T2967 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1171879 T2967 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1171879 T2967 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1171879 T2967 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1171880 T2967 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1171880 T2967 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1171880 T2967 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1171880 T2967 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1171884 T2967 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1171884 T2967 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1171884 T2967 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53573/solr
   [junit4]   2> 1171885 T2967 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1171887 T2967 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1171892 T2987 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@51e210e5 name:ZooKeeperConnection Watcher:127.0.0.1:53573 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1171893 T2967 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1171901 T2967 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1171905 T2989 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@660d1757 name:ZooKeeperConnection Watcher:127.0.0.1:53573/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1171905 T2967 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1171910 T2967 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1171921 T2967 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1171929 T2967 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1171935 T2967 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53576_siodz%2Fzu
   [junit4]   2> 1171938 T2967 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53576_siodz%2Fzu
   [junit4]   2> 1171954 T2967 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1171966 T2967 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1171973 T2967 oasc.Overseer.start Overseer (id=90661446660325379-127.0.0.1:53576_siodz%2Fzu-n_0000000000) starting
   [junit4]   2> 1171982 T2967 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1171993 T2991 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1171994 T2967 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1172003 T2967 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1172008 T2967 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1172016 T2990 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1172026 T2992 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1172026 T2992 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1172029 T2992 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1173531 T2990 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1173532 T2990 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:53576/siodz/zu",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53576_siodz%2Fzu",
   [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":null}
   [junit4]   2> 1173533 T2990 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 1173533 T2990 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1173543 T2989 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> 1174035 T2992 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1174036 T2992 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383383890928/collection1
   [junit4]   2> 1174036 T2992 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 1174038 T2992 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1174038 T2992 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 1174041 T2992 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383383890928/collection1/'
   [junit4]   2> 1174042 T2992 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-1383383890928/collection1/lib/classes/' to classloader
   [junit4]   2> 1174043 T2992 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-1383383890928/collection1/lib/README' to classloader
   [junit4]   2> 1174123 T2992 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 1174197 T2992 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1174202 T2992 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1174213 T2992 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1174750 T2992 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1174750 T2992 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1174751 T2992 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1174759 T2992 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1174763 T2992 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1174796 T2992 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1174804 T2992 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1174812 T2992 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1174816 T2992 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1174817 T2992 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1174817 T2992 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1174820 T2992 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1174821 T2992 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1174821 T2992 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 1174822 T2992 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383383890928/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383383890684/control/data/
   [junit4]   2> 1174822 T2992 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3e002979
   [junit4]   2> 1174823 T2992 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-1383383890684/control/data
   [junit4]   2> 1174825 T2992 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383383890684/control/data/index/
   [junit4]   2> 1174825 T2992 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383383890684/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1174826 T2992 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-1383383890684/control/data/index
   [junit4]   2> 1174826 T2992 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=15, maxMergeAtOnceExplicit=39, maxMergedSegmentMB=30.7958984375, floorSegmentMB=2.10546875, forceMergeDeletesPctAllowed=15.253530529863706, segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 1174830 T2992 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-1383383890684/control/data/index,segFN=segments_1,generation=1}
   [junit4]   2> 1174830 T2992 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1174833 T2992 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1174834 T2992 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1174834 T2992 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1174834 T2992 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1174835 T2992 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1174835 T2992 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1174835 T2992 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1174836 T2992 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1174836 T2992 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1174837 T2992 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1174837 T2992 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1174837 T2992 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1174837 T2992 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1174838 T2992 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1174838 T2992 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1174850 T2992 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1174854 T2992 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1174854 T2992 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1174855 T2992 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=46, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5856233705673677]
   [junit4]   2> 1174857 T2992 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-1383383890684/control/data/index,segFN=segments_1,generation=1}
   [junit4]   2> 1174857 T2992 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1174857 T2992 oass.SolrIndexSearcher.<init> Opening Searcher@7c692386 main
   [junit4]   2> 1174865 T2993 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7c692386 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1174866 T2992 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1174867 T2992 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53576/siodz/zu collection:control_collection shard:shard1
   [junit4]   2> 1174870 T2992 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 1174895 T2992 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1174905 T2992 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1174905 T2992 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 1174905 T2992 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53576/siodz/zu/collection1/
   [junit4]   2> 1174905 T2992 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1174906 T2992 oasc.SyncStrategy.syncToMe http://127.0.0.1:53576/siodz/zu/collection1/ has no replicas
   [junit4]   2> 1174906 T2992 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53576/siodz/zu/collection1/ shard1
   [junit4]   2> 1174906 T2992 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 1175057 T2990 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1175084 T2989 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> 1175133 T2992 oasc.ZkController.register We are http://127.0.0.1:53576/siodz/zu/collection1/ and leader is http://127.0.0.1:53576/siodz/zu/collection1/
   [junit4]   2> 1175133 T2992 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53576/siodz/zu
   [junit4]   2> 1175133 T2992 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1175134 T2992 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1175134 T2992 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1175138 T2992 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1175140 T2967 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1175141 T2967 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1175144 T2967 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1175148 T2996 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f1f83b2 name:ZooKeeperConnection Watcher:127.0.0.1:53573/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1175149 T2967 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1175152 T2967 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1175159 T2967 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
   [junit4]   2> 1175482 T2967 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1175487 T2967 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53580
   [junit4]   2> 1175488 T2967 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1175489 T2967 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1175489 T2967 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383383894615
   [junit4]   2> 1175490 T2967 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383383894615/'
   [junit4]   2> 1175518 T2967 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-1383383894615/solr.xml
   [junit4]   2> 1175597 T2967 oasc.CoreContainer.<init> New CoreContainer 143021873
   [junit4]   2> 1175597 T2967 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383383894615/]
   [junit4]   2> 1175599 T2967 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 240000
   [junit4]   2> 1175599 T2967 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1175599 T2967 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1175600 T2967 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1175600 T2967 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1175600 T2967 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1175600 T2967 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1175600 T2967 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1175601 T2967 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1175606 T2967 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1175607 T2967 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1175607 T2967 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53573/solr
   [junit4]   2> 1175607 T2967 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1175609 T2967 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1175614 T3007 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@36ecd181 name:ZooKeeperConnection Watcher:127.0.0.1:53573 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1175615 T2967 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1175623 T2967 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1175628 T3009 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@63beb210 name:ZooKeeperConnection Watcher:127.0.0.1:53573/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1175629 T2967 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1175642 T2967 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1176606 T2990 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1176607 T2990 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:53576/siodz/zu",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53576_siodz%2Fzu",
   [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> 1176620 T3009 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> 1176620 T2996 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> 1176620 T2989 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> 1176657 T2967 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53580_siodz%2Fzu
   [junit4]   2> 1176661 T2967 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53580_siodz%2Fzu
   [junit4]   2> 1176669 T2996 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1176669 T2989 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1176670 T3009 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1176689 T3010 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1176689 T3010 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1176693 T3010 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1178141 T2990 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1178143 T2990 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:53580/siodz/zu",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53580_siodz%2Fzu",
   [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":null}
   [junit4]   2> 1178144 T2990 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
   [junit4]   2> 1178144 T2990 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1178155 T2989 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> 1178155 T3009 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> 1178156 T2996 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> 1178696 T3010 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1178696 T3010 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383383894615/collection1
   [junit4]   2> 1178697 T3010 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1178698 T3010 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1178699 T3010 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1178702 T3010 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383383894615/collection1/'
   [junit4]   2> 1178704 T3010 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-1383383894615/collection1/lib/classes/' to classloader
   [junit4]   2> 1178704 T3010 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-1383383894615/collection1/lib/README' to classloader
   [junit4]   2> 1178793 T3010 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 1178867 T3010 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1178871 T3010 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1178883 T3010 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1179553 T3010 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1179553 T3010 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1179554 T3010 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1179568 T3010 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1179572 T3010 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1179617 T3010 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1179626 T3010 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1179634 T3010 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1179639 T3010 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1179640 T3010 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1179641 T3010 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1179644 T3010 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1179645 T3010 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1179645 T3010 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 1179645 T3010 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383383894615/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383383890684/jetty1/
   [junit4]   2> 1179646 T3010 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3e002979
   [junit4]   2> 1179647 T3010 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-1383383890684/jetty1
   [junit4]   2> 1179648 T3010 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383383890684/jetty1/index/
   [junit4]   2> 1179648 T3010 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383383890684/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 1179649 T3010 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-1383383890684/jetty1/index
   [junit4]   2> 1179650 T3010 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=15, maxMergeAtOnceExplicit=39, maxMergedSegmentMB=30.7958984375, floorSegmentMB=2.10546875, forceMergeDeletesPctAllowed=15.253530529863706, segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 1179654 T3010 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-1383383890684/jetty1/index,segFN=segments_1,generation=1}
   [junit4]   2> 1179655 T3010 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1179660 T3010 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1179661 T3010 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1179661 T3010 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1179661 T3010 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1179662 T3010 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1179662 T3010 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1179663 T3010 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1179664 T3010 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1179664 T3010 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1179669 T3010 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1179670 T3010 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1179670 T3010 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1179670 T3010 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1179671 T3010 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1179671 T3010 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1179684 T3010 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1179691 T3010 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1179691 T3010 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1179692 T3010 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=46, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5856233705673677]
   [junit4]   2> 1179694 T3010 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-1383383890684/jetty1/index,segFN=segments_1,generation=1}
   [junit4]   2> 1179694 T3010 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1179695 T3010 oass.SolrIndexSearcher.<init> Opening Searcher@6551424d main
   [junit4]   2> 1179701 T3011 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6551424d main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1179704 T3010 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1179704 T3010 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53580/siodz/zu collection:collection1 shard:shard1
   [junit4]   2> 1179707 T3010 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1179732 T3010 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1179740 T3010 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1179741 T3010 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 1179741 T3010 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53580/siodz/zu/collection1/
   [junit4]   2> 1179741 T3010 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1179742 T3010 oasc.SyncStrategy.syncToMe http://127.0.0.1:53580/siodz/zu/collection1/ has no replicas
   [junit4]   2> 1179742 T3010 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53580/siodz/zu/collection1/ shard1
   [junit4]   2> 1179742 T3010 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1181173 T2990 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1181190 T2989 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> 1181190 T2996 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> 1181190 T3009 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> 1181226 T3010 oasc.ZkController.register We are http://127.0.0.1:53580/siodz/zu/collection1/ and leader is http://127.0.0.1:53580/siodz/zu/collection1/
   [junit4]   2> 1181226 T3010 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53580/siodz/zu
   [junit4]   2> 1181226 T3010 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1181227 T3010 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1181227 T3010 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1181231 T3010 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1181234 T2967 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1181234 T2967 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1181527 T2967 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1181531 T2967 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53583
   [junit4]   2> 1181532 T2967 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1181533 T2967 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1181533 T2967 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383383900691
   [junit4]   2> 1181534 T2967 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383383900691/'
   [junit4]   2> 1181561 T2967 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-jetty2-1383383900691/solr.xml
   [junit4]   2> 1181629 T2967 oasc.CoreContainer.<init> New CoreContainer 1049075278
   [junit4]   2> 1181630 T2967 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383383900691/]
   [junit4]   2> 1181631 T2967 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 240000
   [junit4]   2> 1181632 T2967 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1181632 T2967 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1181632 T2967 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1181632 T2967 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1181633 T2967 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1181633 T2967 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1181633 T2967 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1181633 T2967 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1181637 T2967 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1181637 T2967 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1181637 T2967 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53573/solr
   [junit4]   2> 1181638 T2967 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1181639 T2967 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1181643 T3023 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3853092d name:ZooKeeperConnection Watcher:127.0.0.1:53573 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1181644 T2967 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1181651 T2967 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1181654 T3025 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4a34e6b3 name:ZooKeeperConnection Watcher:127.0.0.1:53573/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1181655 T2967 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1181665 T2967 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1182676 T2967 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53583_siodz%2Fzu
   [junit4]   2> 1182678 T2967 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53583_siodz%2Fzu
   [junit4]   2> 1182691 T3009 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1182691 T3025 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1182692 T2996 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1182692 T2989 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1182708 T2990 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1182710 T2990 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:53580/siodz/zu",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53580_siodz%2Fzu",
   [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> 1182711 T3026 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1182711 T3026 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1182713 T3026 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1182721 T2990 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:53583/siodz/zu",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53583_siodz%2Fzu",
   [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":null}
   [junit4]   2> 1182721 T2990 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 1182722 T2990 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 1182733 T3009 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> 1182734 T3025 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> 1182734 T2989 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> 1182734 T2996 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> 1183716 T3026 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1183716 T3026 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383383900691/collection1
   [junit4]   2> 1183716 T3026 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1183718 T3026 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1183718 T3026 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1183721 T3026 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383383900691/collection1/'
   [junit4]   2> 1183722 T3026 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-1383383900691/collection1/lib/classes/' to classloader
   [junit4]   2> 1183723 T3026 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-1383383900691/collection1/lib/README' to classloader
   [junit4]   2> 1183779 T3026 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 1183843 T3026 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1183847 T3026 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1183855 T3026 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1184377 T3026 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1184378 T3026 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1184378 T3026 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1184386 T3026 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1184390 T3026 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1184420 T3026 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1184427 T3026 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1184432 T3026 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1184435 T3026 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1184436 T3026 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1184436 T3026 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1184439 T3026 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1184439 T3026 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1184439 T3026 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 1184440 T3026 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383383900691/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383383890684/jetty2/
   [junit4]   2> 1184440 T3026 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3e002979
   [junit4]   2> 1184441 T3026 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-1383383890684/jetty2
   [junit4]   2> 1184441 T3026 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383383890684/jetty2/index/
   [junit4]   2> 1184442 T3026 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383383890684/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 1184442 T3026 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-1383383890684/jetty2/index
   [junit4]   2> 1184445 T3026 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=15, maxMergeAtOnceExplicit=39, maxMergedSegmentMB=30.7958984375, floorSegmentMB=2.10546875, forceMergeDeletesPctAllowed=15.253530529863706, segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 1184449 T3026 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-1383383890684/jetty2/index,segFN=segments_1,generation=1}
   [junit4]   2> 1184449 T3026 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1184455 T3026 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1184455 T3026 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1184456 T3026 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1184456 T3026 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1184456 T3026 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1184457 T3026 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1184458 T3026 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1184459 T3026 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1184459 T3026 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1184460 T3026 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1184461 T3026 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1184461 T3026 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1184461 T3026 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1184462 T3026 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1184463 T3026 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1184477 T3026 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1184482 T3026 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1184482 T3026 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1184483 T3026 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=46, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5856233705673677]
   [junit4]   2> 1184485 T3026 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-1383383890684/jetty2/index,segFN=segments_1,generation=1}
   [junit4]   2> 1184486 T3026 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1184486 T3026 oass.SolrIndexSearcher.<init> Opening Searcher@53c0b858 main
   [junit4]   2> 1184492 T3027 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@53c0b858 main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1184495 T3026 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1184495 T3026 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53583/siodz/zu collection:collection1 shard:shard2
   [junit4]   2> 1184498 T3026 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 1184517 T3026 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 1184525 T3026 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1184525 T3026 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 1184525 T3026 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53583/siodz/zu/collection1/
   [junit4]   2> 1184526 T3026 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1184526 T3026 oasc.SyncStrategy.syncToMe http://127.0.0.1:53583/siodz/zu/collection1/ has no replicas
   [junit4]   2> 1184526 T3026 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53583/siodz/zu/collection1/ shard2
   [junit4]   2> 1184527 T3026 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 1185764 T2990 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1185790 T3009 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> 1185790 T3025 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> 1185790 T2996 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> 1185790 T2989 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> 1185839 T3026 oasc.ZkController.register We are http://127.0.0.1:53583/siodz/zu/collection1/ and leader is http://127.0.0.1:53583/siodz/zu/collection1/
   [junit4]   2> 1185840 T3026 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53583/siodz/zu
   [junit4]   2> 1185840 T3026 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1185841 T3026 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1185841 T3026 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1185846 T3026 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1185849 T2967 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1185849 T2967 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1186194 T2967 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1186198 T2967 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53586
   [junit4]   2> 1186200 T2967 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1186201 T2967 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1186201 T2967 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383383905307
   [junit4]   2> 1186202 T2967 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383383905307/'
   [junit4]   2> 1186237 T2967 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-1383383905307/solr.xml
   [junit4]   2> 1186323 T2967 oasc.CoreContainer.<init> New CoreContainer 536738766
   [junit4]   2> 1186323 T2967 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383383905307/]
   [junit4]   2> 1186325 T2967 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 240000
   [junit4]   2> 1186325 T2967 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
   [junit4]   2> 1186325 T2967 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1186326 T2967 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1186326 T2967 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1186326 T2967 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1186327 T2967 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1186327 T2967 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1186327 T2967 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1186331 T2967 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1186331 T2967 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1186331 T2967 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53573/solr
   [junit4]   2> 1186332 T2967 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1186335 T2967 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1186340 T3039 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6acb4e15 name:ZooKeeperConnection Watcher:127.0.0.1:53573 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1186341 T2967 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1186349 T2967 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1186354 T3041 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7bd412f8 name:ZooKeeperConnection Watcher:127.0.0.1:53573/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1186354 T2967 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1186366 T2967 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1187310 T2990 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1187312 T2990 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:53583/siodz/zu",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53583_siodz%2Fzu",
   [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> 1187321 T3025 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> 1187322 T3009 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> 1187322 T3041 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> 1187323 T2989 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> 1187324 T2996 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> 1187382 T2967 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53586_siodz%2Fzu
   [junit4]   2> 1187385 T2967 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53586_siodz%2Fzu
   [junit4]   2> 1187394 T3041 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1187394 T2996 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1187394 T3025 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1187394 T2989 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1187394 T3009 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1187409 T3042 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1187409 T3042 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1187412 T3042 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1188840 T2990 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1188842 T2990 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:53586/siodz/zu",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53586_siodz%2Fzu",
   [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":null}
   [junit4]   2> 1188842 T2990 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
   [junit4]   2> 1188842 T2990 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1188853 T3025 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> 1188854 T3009 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> 1188854 T2989 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> 1188854 T3041 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> 1188854 T2996 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> 1189416 T3042 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1189416 T3042 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383383905307/collection1
   [junit4]   2> 1189416 T3042 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1189418 T3042 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1189418 T3042 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1189421 T3042 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383383905307/collection1/'
   [junit4]   2> 1189425 T3042 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-1383383905307/collection1/lib/classes/' to classloader
   [junit4]   2> 1189425 T3042 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-1383383905307/collection1/lib/README' to classloader
   [junit4]   2> 1189508 T3042 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
   [junit4]   2> 1189597 T3042 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1189600 T3042 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1189613 T3042 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1190204 T3042 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1190205 T3042 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1190205 T3042 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1190213 T3042 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1190216 T3042 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1190248 T3042 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1190257 T3042 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1190266 T3042 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1190270 T3042 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1190270 T3042 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1190270 T3042 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1190274 T3042 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1190274 T3042 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1190275 T3042 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 1190275 T3042 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383383905307/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383383890684/jetty3/
   [junit4]   2> 1190275 T3042 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3e002979
   [junit4]   2> 1190277 T3042 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-1383383890684/jetty3
   [junit4]   2> 1190277 T3042 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383383890684/jetty3/index/
   [junit4]   2> 1190277 T3042 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383383890684/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 1190278 T3042 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-1383383890684/jetty3/index
   [junit4]   2> 1190278 T3042 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=15, maxMergeAtOnceExplicit=39, maxMergedSegmentMB=30.7958984375, floorSegmentMB=2.10546875, forceMergeDeletesPctAllowed=15.253530529863706, segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 1190282 T3042 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-1383383890684/jetty3/index,segFN=segments_1,generation=1}
   [junit4]   2> 1190283 T3042 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1190288 T3042 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1190289 T3042 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1190289 T3042 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1190290 T3042 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1190290 T3042 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1190290 T3042 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1190291 T3042 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1190292 T3042 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1190292 T3042 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1190293 T3042 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1190294 T3042 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1190294 T3042 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1190295 T3042 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1190295 T3042 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1190296 T3042 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1190308 T3042 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1190313 T3042 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1190314 T3042 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1190315 T3042 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=46, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.5856233705673677]
   [junit4]   2> 1190317 T3042 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-1383383890684/jetty3/index,segFN=segments_1,generation=1}
   [junit4]   2> 1190318 T3042 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1190318 T3042 oass.SolrIndexSearcher.<init> Opening Searcher@30374e9f main
   [junit4]   2> 1190329 T3043 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@30374e9f main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1190332 T3042 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1190332 T3042 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53586/siodz/zu collection:collection1 shard:shard1
   [junit4]   2> 1190342 T3042 oasc.ZkController.register We are http://127.0.0.1:53586/siodz/zu/collection1/ and leader is http://127.0.0.1:53580/siodz/zu/collection1/
   [junit4]   2> 1190342 T3042 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53586/siodz/zu
   [junit4]   2> 1190342 T3042 oasc.ZkController.checkRecovery Core needs to recover:collection1
   [junit4]   2> 1190342 T3042 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
   [junit4]   2> ASYNC  NEW_CORE C859 name=collection1 org.apache.solr.core.SolrCore@3b0a177d url=http://127.0.0.1:53586/siodz/zu/collection1 node=127.0.0.1:53586_siodz%2Fzu C859_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:53586/siodz/zu, core=collection1, node_name=127.0.0.1:53586_siodz%2Fzu}
   [junit4]   2> 1190343 T3044 C859 P53586 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
   [junit4]   2> 1190343 T3044 C859 P53586 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
   [junit4]   2> 1190344 T3044 C859 P53586 oasc.ZkController.publish publishing core=collection1 state=recovering
   [junit4]   2> 1190344 T3044 C859 P53586 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1190349 T3042 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1190350 T3000 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
   [junit4]   2> 1190353 T2967 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/workspace/Lucene-Solr-4.x-MacOSX/solr/build/solr-core/test/J0
   [junit4]   2> 1190354 T2967 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1190369 T2990 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1190373 T2990 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"recovering",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:53586/siodz/zu",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53586_siodz%2Fzu",
   [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_node3"}
   [junit4]   2> 1190383 T3009 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> 1190383 T3025 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> 1190383 T2996 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> 1190386 T2989 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> 1190386 T3041 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clustersta

[...truncated too long message...]

 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/90661446660325394-core_node7-n_0000000003 (0)
   [junit4]   1>        /solr/collections/collection1/leader_elect/shard1/election/90661446660325397-core_node1-n_0000000005 (0)
   [junit4]   1>        /solr/collections/collection1/leader_elect/shard1/election/90661446660325398-core_node5-n_0000000006 (0)
   [junit4]   1>        /solr/collections/collection1/leader_elect/shard1/election/90661446660325396-core_node3-n_0000000004 (0)
   [junit4]   1>      /solr/collections/collection1/leader_elect/shard2 (1)
   [junit4]   1>       /solr/collections/collection1/leader_elect/shard2/election (2)
   [junit4]   1>        /solr/collections/collection1/leader_elect/shard2/election/90661446660325388-core_node4-n_0000000001 (0)
   [junit4]   1>        /solr/collections/collection1/leader_elect/shard2/election/90661446660325392-core_node6-n_0000000002 (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:53609_siodz%2Fzu",
   [junit4]   1>            "base_url":"http://127.0.0.1:53609/siodz/zu"}
   [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:53590_siodz%2Fzu",
   [junit4]   1>            "base_url":"http://127.0.0.1:53590/siodz/zu"}
   [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/90661446660325379-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:53576_siodz%2Fzu",
   [junit4]   1>            "base_url":"http://127.0.0.1:53576/siodz/zu"}
   [junit4]   1>   /solr/overseer_elect (2)
   [junit4]   1>    /solr/overseer_elect/election (7)
   [junit4]   1>     /solr/overseer_elect/election/90661446660325388-127.0.0.1:53590_siodz%2Fzu-n_0000000004 (0)
   [junit4]   1>     /solr/overseer_elect/election/90661446660325398-127.0.0.1:53597_siodz%2Fzu-n_0000000010 (0)
   [junit4]   1>     /solr/overseer_elect/election/90661446660325397-127.0.0.1:53580_siodz%2Fzu-n_0000000009 (0)
   [junit4]   1>     /solr/overseer_elect/election/90661446660325396-127.0.0.1:53586_siodz%2Fzu-n_0000000008 (0)
   [junit4]   1>     /solr/overseer_elect/election/90661446660325392-127.0.0.1:53604_siodz%2Fzu-n_0000000006 (0)
   [junit4]   1>     /solr/overseer_elect/election/90661446660325379-127.0.0.1:53576_siodz%2Fzu-n_0000000000 (0)
   [junit4]   1>     /solr/overseer_elect/election/90661446660325394-127.0.0.1:53609_siodz%2Fzu-n_0000000007 (0)
   [junit4]   1>    /solr/overseer_elect/leader (0)
   [junit4]   1>    DATA:
   [junit4]   1>        {"id":"90661446660325379-127.0.0.1:53576_siodz%2Fzu-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=A430C890F85CE620 -Dtests.slow=true -Dtests.locale=pt_BR -Dtests.timezone=America/Belize -Dtests.file.encoding=US-ASCII
   [junit4] FAILURE  101s | ChaosMonkeyNothingIsSafeTest.testDistribSearch <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: document count mismatch.  control=27 sum(shards)=28 cloudClient=28
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([A430C890F85CE620:25D646888F03861C]:0)
   [junit4]    > 	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1240)
   [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:744)
   [junit4]   2> 1271785 T2967 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 100572 T2966 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
   [junit4]   2> 1271894 T3094 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 1272997 T3112 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> NOTE: test params are: codec=Lucene41, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=pt_BR, timezone=America/Belize
   [junit4]   2> NOTE: Mac OS X 10.8.5 x86_64/Oracle Corporation 1.7.0_45 (64-bit)/cpus=2,threads=1,free=123138280,total=350748672
   [junit4]   2> NOTE: All tests run in this JVM: [DistributedTermsComponentTest, TestSolrQueryParserResource, SuggesterWFSTTest, TestIndexingPerformance, TestIndexSearcher, TestQuerySenderNoQuery, TestCSVResponseWriter, TestValueSourceCache, TestSolrJ, AlternateDirectoryTest, TestCollationField, TestSuggestSpellingConverter, PrimUtilsTest, TestStressLucene, SolrXmlInZkTest, TestBinaryResponseWriter, BasicDistributedZk2Test, PingRequestHandlerTest, ParsingFieldUpdateProcessorsTest, XsltUpdateRequestHandlerTest, TestSerializedLuceneMatchVersion, TestSolr4Spatial, StatsComponentTest, URLClassifyProcessorTest, TestLFUCache, AssignTest, TestUtils, TestJmxIntegration, TestSchemaResource, TestLMDirichletSimilarityFactory, TestDFRSimilarityFactory, TestSweetSpotSimilarityFactory, DeleteShardTest, TestReversedWildcardFilterFactory, TestHashPartitioner, TestFaceting, TestManagedSchema, TestGroupingSearch, UnloadDistributedZkTest, TermVectorComponentTest, EchoParamsTest, TestCollationKeyRangeQueries, SystemInfoHandlerTest, SOLR749Test, TestZkChroot, InfoHandlerTest, TestFieldResource, CoreAdminHandlerTest, TestPostingsSolrHighlighter, TestNumberUtils, TestQueryUtils, SuggesterFSTTest, RequestHandlersTest, StandardRequestHandlerTest, TestDynamicFieldCollectionResource, TestElisionMultitermQuery, TestRandomDVFaceting, TestArbitraryIndexDir, ConvertedLegacyTest, HdfsChaosMonkeySafeLeaderTest, ZkControllerTest, DeleteReplicaTest, TestXIncludeConfig, TestManagedSchemaFieldResource, TestNonNRTOpen, BadIndexSchemaTest, TestUpdate, TestQueryTypes, SchemaVersionSpecificBehaviorTest, IndexSchemaTest, TestFastOutputStream, UpdateRequestProcessorFactoryTest, TestWordDelimiterFilterFactory, FieldAnalysisRequestHandlerTest, TestFieldCollectionResource, TimeZoneUtilsTest, SignatureUpdateProcessorFactoryTest, SolrIndexConfigTest, UpdateParamsTest, PeerSyncTest, DocValuesMultiTest, TestCopyFieldCollectionResource, DirectUpdateHandlerOptimizeTest, CoreMergeIndexesAdminHandlerTest, TestCodecSupport, SuggesterTest, TestSolrDeletionPolicy2, DefaultValueUpdateProcessorTest, TestAtomicUpdateErrorCases, TestPseudoReturnFields, TestSearchPerf, SyncSliceTest, ShardSplitTest, AliasIntegrationTest, TestDocumentBuilder, TestSolrQueryParser, TestSort, QueryResultKeyTest, NotRequiredUniqueKeyTest, OpenCloseCoreStressTest, TestDocSet, SolrTestCaseJ4Test, TestCoreContainer, CollectionsAPIDistributedZkTest, HdfsBasicDistributedZkTest, TestMultiCoreConfBootstrap, TestFiltering, TestMergePolicyConfig, ExternalFileFieldSortTest, MultiTermTest, ChaosMonkeyNothingIsSafeTest]
   [junit4] Completed in 101.87s, 1 test, 1 failure <<< FAILURES!

[...truncated 679 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: 333 suites, 1469 tests, 1 failure, 40 ignored (5 assumptions)

Total time: 91 minutes 53 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:+UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure