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 11:55:05 UTC
[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.8.0-ea-b109) - Build
# 8141 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/8141/
Java: 32bit/jdk1.8.0-ea-b109 -client -XX:+UseSerialGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.testDistribSearch
Error Message:
document count mismatch. control=498 sum(shards)=497 cloudClient=497
Stack Trace:
java.lang.AssertionError: document count mismatch. control=498 sum(shards)=497 cloudClient=497
at __randomizedtesting.SeedInfo.seed([120A4E7290628DC7:93ECC06AE73DEDFB]: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:491)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Build Log:
[...truncated 10816 lines...]
[junit4] Suite: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest
[junit4] 2> 917017 T3026 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /gvn/
[junit4] 2> 917020 T3026 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-ChaosMonkeyNothingIsSafeTest-1383389540960
[junit4] 2> 917021 T3026 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 917022 T3027 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 917122 T3026 oasc.ZkTestServer.run start zk server on port:59299
[junit4] 2> 917124 T3026 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 917210 T3033 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e65df name:ZooKeeperConnection Watcher:127.0.0.1:59299 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 917210 T3026 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 917211 T3026 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 917220 T3026 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 917223 T3035 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d6c04 name:ZooKeeperConnection Watcher:127.0.0.1:59299/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 917223 T3026 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 917224 T3026 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 917230 T3026 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 917234 T3026 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 917238 T3026 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 917242 T3026 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 917243 T3026 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 917250 T3026 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 917252 T3026 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 917257 T3026 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 917258 T3026 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 917263 T3026 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 917263 T3026 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 917268 T3026 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 917269 T3026 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 917273 T3026 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 917274 T3026 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 917278 T3026 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 917279 T3026 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 917281 T3026 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 917282 T3026 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 917286 T3026 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 917286 T3026 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 917289 T3026 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 917290 T3026 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 917357 T3026 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 917363 T3026 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:41664
[junit4] 2> 917363 T3026 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 917364 T3026 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 917364 T3026 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383389541233
[junit4] 2> 917364 T3026 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383389541233/'
[junit4] 2> 917381 T3026 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383389541233/solr.xml
[junit4] 2> 917391 T3026 oasc.CoreContainer.<init> New CoreContainer 24702765
[junit4] 2> 917391 T3026 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383389541233/]
[junit4] 2> 917392 T3026 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 240000
[junit4] 2> 917392 T3026 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 917392 T3026 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 917393 T3026 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 917393 T3026 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 917393 T3026 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 917394 T3026 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 917394 T3026 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 917394 T3026 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 917396 T3026 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 917396 T3026 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 917396 T3026 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59299/solr
[junit4] 2> 917397 T3026 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 917397 T3026 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 917400 T3046 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ca0533 name:ZooKeeperConnection Watcher:127.0.0.1:59299 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 917401 T3026 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 917405 T3026 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 917406 T3048 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@17f1ffe name:ZooKeeperConnection Watcher:127.0.0.1:59299/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 917407 T3026 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 917408 T3026 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 917411 T3026 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 917414 T3026 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 917415 T3026 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41664_gvn
[junit4] 2> 917416 T3026 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:41664_gvn
[junit4] 2> 917418 T3026 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 917421 T3026 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 917423 T3026 oasc.Overseer.start Overseer (id=90661816956616707-127.0.0.1:41664_gvn-n_0000000000) starting
[junit4] 2> 917425 T3026 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 917429 T3050 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 917429 T3026 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 917433 T3026 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 917435 T3026 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 917438 T3049 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 917438 T3051 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 917438 T3051 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 917439 T3051 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 918943 T3049 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 918944 T3049 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:41664/gvn",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:41664_gvn",
[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> 918944 T3049 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 918945 T3049 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 918952 T3048 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> 919439 T3051 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 919440 T3051 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383389541233/collection1
[junit4] 2> 919441 T3051 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 919442 T3051 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 919442 T3051 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 919444 T3051 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383389541233/collection1/'
[junit4] 2> 919445 T3051 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383389541233/collection1/lib/classes/' to classloader
[junit4] 2> 919468 T3051 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383389541233/collection1/lib/README' to classloader
[junit4] 2> 919493 T3051 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 919502 T3051 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 919503 T3051 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 919514 T3051 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 919689 T3051 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 919694 T3051 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 919696 T3051 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 919707 T3051 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 919709 T3051 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 919711 T3051 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 919712 T3051 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 919713 T3051 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 919713 T3051 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 919714 T3051 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 919714 T3051 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 919714 T3051 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 919714 T3051 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383389541233/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/control/data/
[junit4] 2> 919715 T3051 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b781a7
[junit4] 2> 919715 T3051 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/control/data
[junit4] 2> 919715 T3051 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/control/data/index/
[junit4] 2> 919716 T3051 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 919716 T3051 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/control/data/index
[junit4] 2> 919717 T3051 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=2025143335, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 919719 T3051 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 919720 T3051 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 919723 T3051 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 919723 T3051 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 919724 T3051 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 919724 T3051 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 919724 T3051 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 919724 T3051 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 919725 T3051 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 919725 T3051 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 919726 T3051 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 919726 T3051 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 919727 T3051 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 919727 T3051 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 919727 T3051 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 919728 T3051 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 919728 T3051 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 919731 T3051 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 919732 T3051 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 919733 T3051 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 919734 T3051 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=44, maxMergedSegmentMB=9.5517578125, floorSegmentMB=0.453125, forceMergeDeletesPctAllowed=8.717135198639436, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 919735 T3051 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 919735 T3051 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 919735 T3051 oass.SolrIndexSearcher.<init> Opening Searcher@638c9c main
[junit4] 2> 919739 T3052 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@638c9c main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 919740 T3051 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 919740 T3051 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:41664/gvn collection:control_collection shard:shard1
[junit4] 2> 919741 T3051 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 919748 T3051 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 919750 T3051 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 919750 T3051 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 919751 T3051 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:41664/gvn/collection1/
[junit4] 2> 919751 T3051 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 919751 T3051 oasc.SyncStrategy.syncToMe http://127.0.0.1:41664/gvn/collection1/ has no replicas
[junit4] 2> 919752 T3051 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:41664/gvn/collection1/ shard1
[junit4] 2> 919752 T3051 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 920460 T3049 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 920472 T3048 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> 920512 T3051 oasc.ZkController.register We are http://127.0.0.1:41664/gvn/collection1/ and leader is http://127.0.0.1:41664/gvn/collection1/
[junit4] 2> 920512 T3051 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:41664/gvn
[junit4] 2> 920513 T3051 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 920513 T3051 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 920514 T3051 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 920516 T3051 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 920518 T3026 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 920519 T3026 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 920521 T3026 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 920524 T3055 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@53669e name:ZooKeeperConnection Watcher:127.0.0.1:59299/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 920525 T3026 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 920527 T3026 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 920530 T3026 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 920598 T3026 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 920600 T3026 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:45784
[junit4] 2> 920601 T3026 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 920601 T3026 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 920601 T3026 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383389544469
[junit4] 2> 920601 T3026 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383389544469/'
[junit4] 2> 920621 T3026 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383389544469/solr.xml
[junit4] 2> 920638 T3026 oasc.CoreContainer.<init> New CoreContainer 33403985
[junit4] 2> 920639 T3026 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383389544469/]
[junit4] 2> 920639 T3026 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 240000
[junit4] 2> 920640 T3026 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 920640 T3026 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 920640 T3026 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 920641 T3026 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 920641 T3026 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 920641 T3026 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 920642 T3026 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 920642 T3026 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 920643 T3026 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 920643 T3026 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 920644 T3026 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59299/solr
[junit4] 2> 920644 T3026 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 920645 T3026 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 920647 T3066 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1de6f21 name:ZooKeeperConnection Watcher:127.0.0.1:59299 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 920647 T3026 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 920649 T3026 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 920650 T3068 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@16437c1 name:ZooKeeperConnection Watcher:127.0.0.1:59299/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 920651 T3026 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 920661 T3026 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 921664 T3026 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45784_gvn
[junit4] 2> 921666 T3026 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:45784_gvn
[junit4] 2> 921669 T3048 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 921669 T3055 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 921669 T3068 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 921672 T3069 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 921672 T3069 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 921673 T3069 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 921980 T3049 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 921981 T3049 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:41664/gvn",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:41664_gvn",
[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> 921984 T3049 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:45784/gvn",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:45784_gvn",
[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> 921984 T3049 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 921984 T3049 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 921987 T3055 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> 921987 T3048 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> 921987 T3068 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> 922673 T3069 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 922674 T3069 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383389544469/collection1
[junit4] 2> 922674 T3069 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 922675 T3069 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 922676 T3069 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 922678 T3069 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383389544469/collection1/'
[junit4] 2> 922679 T3069 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383389544469/collection1/lib/classes/' to classloader
[junit4] 2> 922679 T3069 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383389544469/collection1/lib/README' to classloader
[junit4] 2> 922707 T3069 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 922715 T3069 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 922717 T3069 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 922724 T3069 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 922873 T3069 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 922877 T3069 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 922878 T3069 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 922889 T3069 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 922891 T3069 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 922893 T3069 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 922894 T3069 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 922894 T3069 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 922894 T3069 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 922895 T3069 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 922895 T3069 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 922896 T3069 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 922896 T3069 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383389544469/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/jetty1/
[junit4] 2> 922896 T3069 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b781a7
[junit4] 2> 922897 T3069 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/jetty1
[junit4] 2> 922897 T3069 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/jetty1/index/
[junit4] 2> 922897 T3069 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 922897 T3069 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/jetty1/index
[junit4] 2> 922898 T3069 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=2025143335, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 922910 T3069 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 922911 T3069 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 922913 T3069 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 922913 T3069 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 922913 T3069 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 922913 T3069 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 922914 T3069 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 922914 T3069 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 922914 T3069 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 922914 T3069 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 922915 T3069 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 922915 T3069 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 922916 T3069 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 922916 T3069 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 922916 T3069 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 922917 T3069 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 922917 T3069 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 922918 T3069 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 922920 T3069 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 922920 T3069 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 922921 T3069 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=44, maxMergedSegmentMB=9.5517578125, floorSegmentMB=0.453125, forceMergeDeletesPctAllowed=8.717135198639436, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 922921 T3069 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 922921 T3069 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 922922 T3069 oass.SolrIndexSearcher.<init> Opening Searcher@199ea55 main
[junit4] 2> 922925 T3070 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@199ea55 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 922927 T3069 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 922927 T3069 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:45784/gvn collection:collection1 shard:shard2
[junit4] 2> 922928 T3069 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 922935 T3069 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 922937 T3069 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 922937 T3069 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 922937 T3069 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:45784/gvn/collection1/
[junit4] 2> 922937 T3069 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 922937 T3069 oasc.SyncStrategy.syncToMe http://127.0.0.1:45784/gvn/collection1/ has no replicas
[junit4] 2> 922938 T3069 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:45784/gvn/collection1/ shard2
[junit4] 2> 922938 T3069 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 923493 T3049 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 923505 T3055 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> 923505 T3048 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> 923505 T3068 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> 923545 T3069 oasc.ZkController.register We are http://127.0.0.1:45784/gvn/collection1/ and leader is http://127.0.0.1:45784/gvn/collection1/
[junit4] 2> 923546 T3069 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:45784/gvn
[junit4] 2> 923547 T3069 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 923547 T3069 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 923547 T3069 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 923550 T3069 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 923552 T3026 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 923553 T3026 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 923625 T3026 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 923628 T3026 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:45158
[junit4] 2> 923628 T3026 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 923629 T3026 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 923629 T3026 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383389547493
[junit4] 2> 923629 T3026 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383389547493/'
[junit4] 2> 923643 T3026 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383389547493/solr.xml
[junit4] 2> 923664 T3026 oasc.CoreContainer.<init> New CoreContainer 6904317
[junit4] 2> 923665 T3026 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383389547493/]
[junit4] 2> 923665 T3026 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 240000
[junit4] 2> 923666 T3026 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 923667 T3026 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 923667 T3026 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 923668 T3026 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 923668 T3026 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 923669 T3026 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 923670 T3026 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 923670 T3026 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 923672 T3026 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 923673 T3026 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 923674 T3026 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59299/solr
[junit4] 2> 923675 T3026 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 923676 T3026 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 923678 T3082 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ae2bdf name:ZooKeeperConnection Watcher:127.0.0.1:59299 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 923679 T3026 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 923682 T3026 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 923684 T3084 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@cbee99 name:ZooKeeperConnection Watcher:127.0.0.1:59299/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 923684 T3026 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 923690 T3026 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 924695 T3026 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45158_gvn
[junit4] 2> 924697 T3026 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:45158_gvn
[junit4] 2> 924701 T3055 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 924701 T3068 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 924701 T3048 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 924701 T3084 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 924705 T3085 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 924705 T3085 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 924706 T3085 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 925012 T3049 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 925012 T3049 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:45784/gvn",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:45784_gvn",
[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_node1"}
[junit4] 2> 925017 T3049 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:45158/gvn",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:45158_gvn",
[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> 925017 T3049 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 925017 T3049 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 925022 T3068 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> 925022 T3084 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> 925022 T3048 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> 925022 T3055 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> 925706 T3085 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 925707 T3085 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383389547493/collection1
[junit4] 2> 925707 T3085 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 925708 T3085 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 925709 T3085 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 925711 T3085 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383389547493/collection1/'
[junit4] 2> 925712 T3085 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383389547493/collection1/lib/classes/' to classloader
[junit4] 2> 925712 T3085 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383389547493/collection1/lib/README' to classloader
[junit4] 2> 925735 T3085 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 925743 T3085 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 925746 T3085 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 925752 T3085 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 925923 T3085 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 925927 T3085 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 925928 T3085 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 925943 T3085 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 925946 T3085 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 925948 T3085 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 925949 T3085 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 925949 T3085 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 925949 T3085 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 925950 T3085 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 925951 T3085 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 925951 T3085 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 925951 T3085 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383389547493/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/jetty2/
[junit4] 2> 925951 T3085 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b781a7
[junit4] 2> 925952 T3085 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/jetty2
[junit4] 2> 925952 T3085 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/jetty2/index/
[junit4] 2> 925953 T3085 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 925953 T3085 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/jetty2/index
[junit4] 2> 925954 T3085 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=2025143335, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 925959 T3085 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 925959 T3085 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 925962 T3085 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 925962 T3085 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 925962 T3085 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 925963 T3085 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 925963 T3085 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 925963 T3085 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 925963 T3085 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 925964 T3085 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 925964 T3085 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 925965 T3085 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 925965 T3085 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 925965 T3085 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 925966 T3085 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 925967 T3085 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 925968 T3085 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 925970 T3085 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 925972 T3085 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 925973 T3085 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 925975 T3085 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=44, maxMergedSegmentMB=9.5517578125, floorSegmentMB=0.453125, forceMergeDeletesPctAllowed=8.717135198639436, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 925977 T3085 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 925977 T3085 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 925978 T3085 oass.SolrIndexSearcher.<init> Opening Searcher@1e8ff84 main
[junit4] 2> 925982 T3086 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1e8ff84 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 925984 T3085 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 925984 T3085 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:45158/gvn collection:collection1 shard:shard1
[junit4] 2> 925985 T3085 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 925993 T3085 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 925996 T3085 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 925996 T3085 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 925996 T3085 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:45158/gvn/collection1/
[junit4] 2> 925996 T3085 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 925997 T3085 oasc.SyncStrategy.syncToMe http://127.0.0.1:45158/gvn/collection1/ has no replicas
[junit4] 2> 925997 T3085 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:45158/gvn/collection1/ shard1
[junit4] 2> 925997 T3085 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 926531 T3049 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 926544 T3055 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> 926545 T3084 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> 926544 T3068 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> 926545 T3048 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> 926556 T3085 oasc.ZkController.register We are http://127.0.0.1:45158/gvn/collection1/ and leader is http://127.0.0.1:45158/gvn/collection1/
[junit4] 2> 926557 T3085 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:45158/gvn
[junit4] 2> 926557 T3085 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 926557 T3085 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 926558 T3085 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 926560 T3085 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 926562 T3026 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 926562 T3026 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 926641 T3026 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 926644 T3026 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:36103
[junit4] 2> 926645 T3026 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 926645 T3026 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 926645 T3026 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383389550503
[junit4] 2> 926646 T3026 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383389550503/'
[junit4] 2> 926680 T3026 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383389550503/solr.xml
[junit4] 2> 926687 T3026 oasc.CoreContainer.<init> New CoreContainer 11701343
[junit4] 2> 926688 T3026 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383389550503/]
[junit4] 2> 926688 T3026 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 240000
[junit4] 2> 926689 T3026 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 926689 T3026 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 926689 T3026 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 926689 T3026 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 926690 T3026 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 926690 T3026 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 926690 T3026 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 926691 T3026 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 926692 T3026 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 926692 T3026 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 926692 T3026 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59299/solr
[junit4] 2> 926693 T3026 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 926694 T3026 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 926696 T3098 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@199ebb6 name:ZooKeeperConnection Watcher:127.0.0.1:59299 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 926697 T3026 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 926701 T3026 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 926703 T3100 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@12e6086 name:ZooKeeperConnection Watcher:127.0.0.1:59299/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 926703 T3026 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 926709 T3026 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 927713 T3026 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36103_gvn
[junit4] 2> 927715 T3026 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36103_gvn
[junit4] 2> 927718 T3055 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 927718 T3048 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 927718 T3068 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 927718 T3100 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 927718 T3084 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 927722 T3101 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 927722 T3101 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 927723 T3101 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 928052 T3049 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 928053 T3049 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:45158/gvn",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:45158_gvn",
[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_node2"}
[junit4] 2> 928056 T3049 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:36103/gvn",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:36103_gvn",
[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> 928056 T3049 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 928056 T3049 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 928060 T3068 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> 928060 T3048 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> 928060 T3084 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> 928060 T3055 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> 928060 T3100 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> 928723 T3101 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 928724 T3101 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383389550503/collection1
[junit4] 2> 928724 T3101 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 928725 T3101 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 928725 T3101 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 928726 T3101 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383389550503/collection1/'
[junit4] 2> 928727 T3101 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383389550503/collection1/lib/classes/' to classloader
[junit4] 2> 928727 T3101 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383389550503/collection1/lib/README' to classloader
[junit4] 2> 928747 T3101 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 928769 T3101 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 928770 T3101 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 928779 T3101 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 928913 T3101 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 928917 T3101 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 928919 T3101 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 928930 T3101 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 928932 T3101 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 928934 T3101 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 928935 T3101 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 928935 T3101 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 928935 T3101 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 928936 T3101 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 928936 T3101 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 928937 T3101 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 928937 T3101 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383389550503/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/jetty3/
[junit4] 2> 928937 T3101 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b781a7
[junit4] 2> 928938 T3101 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/jetty3
[junit4] 2> 928938 T3101 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/jetty3/index/
[junit4] 2> 928938 T3101 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 928939 T3101 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/jetty3/index
[junit4] 2> 928939 T3101 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: minMergeSize=0, mergeFactor=10, maxMergeSize=2025143335, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1]
[junit4] 2> 928941 T3101 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/jetty3/index,segFN=segments_1,generation=1}
[junit4] 2> 928941 T3101 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 928944 T3101 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 928944 T3101 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 928944 T3101 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 928944 T3101 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 928945 T3101 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 928945 T3101 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 928945 T3101 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 928945 T3101 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 928946 T3101 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 928946 T3101 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 928947 T3101 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 928947 T3101 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 928947 T3101 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 928948 T3101 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 928948 T3101 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 928949 T3101 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 928951 T3101 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 928951 T3101 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 928951 T3101 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=44, maxMergedSegmentMB=9.5517578125, floorSegmentMB=0.453125, forceMergeDeletesPctAllowed=8.717135198639436, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 928952 T3101 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383389540960/jetty3/index,segFN=segments_1,generation=1}
[junit4] 2> 928952 T3101 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 928953 T3101 oass.SolrIndexSearcher.<init> Opening Searcher@429604 main
[junit4] 2> 928956 T3102 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@429604 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 928958 T3101 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 928958 T3101 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:36103/gvn collection:collection1 shard:shard2
[junit4] 2> 928972 T3101 oasc.ZkController.register We are http://127.0.0.1:36103/gvn/collection1/ and leader is http://127.0.0.1:45784/gvn/collection1/
[junit4] 2> 928972 T3101 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:36103/gvn
[junit4] 2> 928972 T3101 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 928973 T3101 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C8041 name=collection1 org.apache.solr.core.SolrCore@da05c1 url=http://127.0.0.1:36103/gvn/collection1 node=127.0.0.1:36103_gvn C8041_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:36103/gvn, core=collection1, node_name=127.0.0.1:36103_gvn}
[junit4] 2> 928973 T3103 C8041 P36103 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 928973 T3103 C8041 P36103 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 928973 T3101 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 928973 T3103 C8041 P36103 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 928974 T3103 C8041 P36103 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 928974 T3026 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 928975 T3026 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 928976 T3064 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 929043 T3026 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 929044 T3026 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:46169
[junit4] 2> 929045 T3026 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 929045 T3026 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 929046 T3026 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty4-1383389552914
[junit4] 2> 929046 T3026 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty4-1383389552914/'
[junit4] 2> 929058 T3026 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty4-1383389552914/solr.xml
[junit4] 2> 929065 T3026 oasc.CoreContainer.<init> New CoreContainer 32885381
[junit4] 2> 929066 T3026 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty4-1383389552914/]
[junit4] 2> 929066 T3026 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 240000
[junit4] 2> 929067 T3026 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 929067 T3026 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 929067 T3026 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 929067 T3026 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 929068 T3026 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 929068 T3026 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 929068 T3026 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 929069 T3026 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 929070 T3026 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 929070 T3026 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 929071 T3026 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59299/solr
[junit4] 2> 929071 T3026 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 929072 T3026 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 929073 T3115 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@cb00e5 name:ZooKeeperConnection Watcher:127.0.0.1:59299 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 929074 T3026 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 929078 T3026 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 929079 T3117 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@adf85a name:ZooKeeperConnection Watcher:127.0.0.1:59299/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 929080 T3026 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 929084 T3026 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 929566 T3049 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 929566 T3049 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:36103/gvn",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:36103_gvn",
[junit4] 2> "sha
[...truncated too long message...]
> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:41664/gvn",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:41664_gvn",
[junit4] 1> "leader":"true"}}}},
[junit4] 1> "router":{"name":"compositeId"},
[junit4] 1> "autoCreated":"true",
[junit4] 1> "maxShardsPerNode":"1"},
[junit4] 1> "collection1":{
[junit4] 1> "replicationFactor":"1",
[junit4] 1> "shards":{
[junit4] 1> "shard1":{
[junit4] 1> "range":"80000000-ffffffff",
[junit4] 1> "state":"active",
[junit4] 1> "replicas":{
[junit4] 1> "core_node2":{
[junit4] 1> "state":"down",
[junit4] 1> "base_url":"http://127.0.0.1:45158/gvn",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:45158_gvn"},
[junit4] 1> "core_node4":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:46169/gvn",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:46169_gvn",
[junit4] 1> "leader":"true"},
[junit4] 1> "core_node6":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:36394/gvn",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:36394_gvn"}}},
[junit4] 1> "shard2":{
[junit4] 1> "range":"0-7fffffff",
[junit4] 1> "state":"active",
[junit4] 1> "replicas":{
[junit4] 1> "core_node1":{
[junit4] 1> "state":"down",
[junit4] 1> "base_url":"http://127.0.0.1:45784/gvn",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:45784_gvn"},
[junit4] 1> "core_node3":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:36103/gvn",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:36103_gvn",
[junit4] 1> "leader":"true"},
[junit4] 1> "core_node5":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:44231/gvn",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:44231_gvn"},
[junit4] 1> "core_node7":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:39491/gvn",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:39491_gvn"}}}},
[junit4] 1> "router":{"name":"compositeId"},
[junit4] 1> "autoCreated":"true",
[junit4] 1> "maxShardsPerNode":"1"}}
[junit4] 1>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeyNothingIsSafeTest -Dtests.method=testDistribSearch -Dtests.seed=120A4E7290628DC7 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=hu_HU -Dtests.timezone=Pacific/Pago_Pago -Dtests.file.encoding=UTF-8
[junit4] FAILURE 159s J1 | ChaosMonkeyNothingIsSafeTest.testDistribSearch <<<
[junit4] > Throwable #1: java.lang.AssertionError: document count mismatch. control=498 sum(shards)=497 cloudClient=497
[junit4] > at __randomizedtesting.SeedInfo.seed([120A4E7290628DC7:93ECC06AE73DEDFB]: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:724)
[junit4] 2> 1076376 T3026 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 159364 T3025 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
[junit4] 2> 1076568 T3293 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 1077663 T3310 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=CheapBastard, sim=DefaultSimilarity, locale=hu_HU, timezone=Pacific/Pago_Pago
[junit4] 2> NOTE: Linux 3.8.0-32-generic i386/Oracle Corporation 1.8.0-ea (32-bit)/cpus=8,threads=3,free=90824848,total=185004032
[junit4] 2> NOTE: All tests run in this JVM: [TestMaxScoreQueryParser, HdfsSyncSliceTest, PluginInfoTest, TestIBSimilarityFactory, TestUpdate, RAMDirectoryFactoryTest, CurrencyFieldOpenExchangeTest, TestAtomicUpdateErrorCases, TestPartialUpdateDeduplication, TestDocBasedVersionConstraints, OpenCloseCoreStressTest, DocValuesMissingTest, NumericFieldsTest, DistanceFunctionTest, ZkNodePropsTest, TestSweetSpotSimilarityFactory, TestCodecSupport, TestFiltering, TestZkChroot, SolrCoreCheckLockOnStartupTest, TimeZoneUtilsTest, CollectionsAPIDistributedZkTest, SpellCheckComponentTest, TestQuerySenderNoQuery, TestReloadAndDeleteDocs, SpellingQueryConverterTest, SuggesterWFSTTest, TestFastWriter, TestWordDelimiterFilterFactory, TestAnalyzeInfixSuggestions, CoreContainerCoreInitFailuresTest, StatsComponentTest, DocValuesMultiTest, TestRandomFaceting, TestDefaultSearchFieldResource, TestBinaryResponseWriter, SolrRequestParserTest, OpenExchangeRatesOrgProviderTest, BadIndexSchemaTest, DirectSolrSpellCheckerTest, XsltUpdateRequestHandlerTest, DocumentAnalysisRequestHandlerTest, HighlighterTest, QueryResultKeyTest, HdfsBasicDistributedZk2Test, DirectUpdateHandlerTest, TestJmxIntegration, ParsingFieldUpdateProcessorsTest, AssignTest, TestDistributedGrouping, TestRecovery, RequiredFieldsTest, DeleteReplicaTest, SignatureUpdateProcessorFactoryTest, TestFastLRUCache, TestOmitPositions, NotRequiredUniqueKeyTest, PreAnalyzedFieldTest, TestDefaultSimilarityFactory, HdfsLockFactoryTest, TestRangeQuery, StandardRequestHandlerTest, SolrPluginUtilsTest, TestRecoveryHdfs, TestManagedSchema, NoCacheHeaderTest, TestStressLucene, TestSolrQueryParserResource, TestArbitraryIndexDir, BasicDistributedZk2Test, TestFoldingMultitermQuery, SolrCmdDistributorTest, PathHierarchyTokenizerFactoryTest, TestHashPartitioner, CurrencyFieldXmlFileTest, TestMultiCoreConfBootstrap, SortByFunctionTest, TestQueryTypes, SuggesterTSTTest, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, LeaderElectionIntegrationTest, BasicZkTest, FullSolrCloudDistribCmdsTest, ClusterStateUpdateTest, ZkSolrClientTest, SliceStateUpdateTest, AutoCommitTest, DistributedSpellCheckComponentTest, TermVectorComponentDistributedTest, TestStressReorder, HardAutoCommitTest, SimpleFacetsTest, TestSolr4Spatial, SolrCoreTest, TestGroupingSearch, TestIndexSearcher, SolrIndexSplitterTest, AnalysisAfterCoreReloadTest, DocValuesTest, SuggesterTest, SpatialFilterTest, WordBreakSolrSpellCheckerTest, DefaultValueUpdateProcessorTest, DebugComponentTest, CacheHeaderTest, TestSurroundQueryParser, DisMaxRequestHandlerTest, PrimitiveFieldTypeTest, RequestHandlersTest, TermVectorComponentTest, TestIndexingPerformance, FastVectorHighlighterTest, LoggingHandlerTest, IndexSchemaTest, TestCSVResponseWriter, TestAnalyzedSuggestions, UniqFieldsUpdateProcessorFactoryTest, PingRequestHandlerTest, SearchHandlerTest, HighlighterConfigTest, AlternateDirectoryTest, ResponseLogComponentTest, SolrIndexConfigTest, TestSolrDeletionPolicy2, MultiTermTest, SampleTest, TestDocSet, TestBinaryField, MinimalSchemaTest, OutputWriterTest, TestFuzzyAnalyzedSuggestions, TestSolrCoreProperties, TestPostingsSolrHighlighter, DirectSolrConnectionTest, TestLuceneMatchVersion, TestPhraseSuggestions, SpellPossibilityIteratorTest, TestXIncludeConfig, EchoParamsTest, TestDFRSimilarityFactory, TestPerFieldSimilarity, TestNumberUtils, TestLMDirichletSimilarityFactory, TestLMJelinekMercerSimilarityFactory, TestJmxMonitoredMap, TestFastOutputStream, ScriptEngineTest, URLClassifyProcessorTest, DateMathParserTest, ChaosMonkeyNothingIsSafeTest]
[junit4] Completed on J1 in 160.90s, 1 test, 1 failure <<< FAILURES!
[...truncated 10 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:421: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:401: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:471: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1259: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:902: There were test failures: 332 suites, 1464 tests, 1 failure, 41 ignored (6 assumptions)
Total time: 42 minutes 5 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.8.0-ea-b109 -client -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-trunk-Linux (64bit/jdk1.8.0-ea-b109) - Build
# 8142 - Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/8142/
Java: 64bit/jdk1.8.0-ea-b109 -XX:-UseCompressedOops -XX:+UseSerialGC
1 tests failed.
FAILED: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest.testDistribSearch
Error Message:
document count mismatch. control=118 sum(shards)=117 cloudClient=117
Stack Trace:
java.lang.AssertionError: document count mismatch. control=118 sum(shards)=117 cloudClient=117
at __randomizedtesting.SeedInfo.seed([476E806C412C2E3:8590661EB34DA2DF]: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:491)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Build Log:
[...truncated 10101 lines...]
[junit4] Suite: org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest
[junit4] 2> 273000 T1003 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 273002 T1003 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-ChaosMonkeyNothingIsSafeTest-1383394563071
[junit4] 2> 273002 T1003 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 273003 T1004 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 273103 T1003 oasc.ZkTestServer.run start zk server on port:32843
[junit4] 2> 273104 T1003 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 273191 T1010 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2cb3e39d name:ZooKeeperConnection Watcher:127.0.0.1:32843 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 273191 T1003 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 273192 T1003 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 273197 T1003 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 273201 T1012 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3fef2beb name:ZooKeeperConnection Watcher:127.0.0.1:32843/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 273202 T1003 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 273202 T1003 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 273206 T1003 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 273208 T1003 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 273210 T1003 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 273213 T1003 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 273214 T1003 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 273218 T1003 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 273218 T1003 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 273222 T1003 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 273222 T1003 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 273224 T1003 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 273224 T1003 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 273226 T1003 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 273226 T1003 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 273228 T1003 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 273228 T1003 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 273230 T1003 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 273230 T1003 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 273231 T1003 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 273232 T1003 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 273234 T1003 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 273234 T1003 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 273235 T1003 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 273235 T1003 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 273290 T1003 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 273296 T1003 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49494
[junit4] 2> 273296 T1003 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 273297 T1003 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 273297 T1003 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383394563306
[junit4] 2> 273297 T1003 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383394563306/'
[junit4] 2> 273308 T1003 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383394563306/solr.xml
[junit4] 2> 273322 T1003 oasc.CoreContainer.<init> New CoreContainer 2038840328
[junit4] 2> 273323 T1003 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383394563306/]
[junit4] 2> 273323 T1003 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 240000
[junit4] 2> 273323 T1003 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 273324 T1003 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 273324 T1003 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 273324 T1003 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 273324 T1003 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 273324 T1003 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 273325 T1003 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 273325 T1003 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 273326 T1003 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 273326 T1003 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 273326 T1003 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:32843/solr
[junit4] 2> 273326 T1003 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 273327 T1003 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 273329 T1023 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@959b4f6 name:ZooKeeperConnection Watcher:127.0.0.1:32843 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 273329 T1003 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 273332 T1003 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 273334 T1025 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4beec9ed name:ZooKeeperConnection Watcher:127.0.0.1:32843/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 273334 T1003 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 273335 T1003 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 273338 T1003 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 273339 T1003 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 273341 T1003 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49494_
[junit4] 2> 273342 T1003 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49494_
[junit4] 2> 273344 T1003 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 273347 T1003 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 273349 T1003 oasc.Overseer.start Overseer (id=90662146085552131-127.0.0.1:49494_-n_0000000000) starting
[junit4] 2> 273351 T1003 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 273353 T1027 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 273353 T1003 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 273355 T1003 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 273356 T1003 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 273358 T1026 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 273359 T1028 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 273359 T1028 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 273360 T1028 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 274860 T1026 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 274861 T1026 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:49494",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49494_",
[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> 274861 T1026 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 274861 T1026 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 274864 T1025 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> 275360 T1028 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 275360 T1028 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383394563306/collection1
[junit4] 2> 275360 T1028 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 275361 T1028 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 275361 T1028 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 275362 T1028 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383394563306/collection1/'
[junit4] 2> 275362 T1028 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383394563306/collection1/lib/classes/' to classloader
[junit4] 2> 275362 T1028 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383394563306/collection1/lib/README' to classloader
[junit4] 2> 275377 T1028 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 275387 T1028 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 275388 T1028 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 275393 T1028 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 275517 T1028 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 275520 T1028 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 275522 T1028 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 275532 T1028 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 275535 T1028 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 275537 T1028 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 275538 T1028 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 275540 T1028 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 275540 T1028 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 275541 T1028 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 275541 T1028 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 275541 T1028 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 275541 T1028 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-controljetty-1383394563306/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/control/data/
[junit4] 2> 275542 T1028 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4503cc23
[junit4] 2> 275542 T1028 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/control/data
[junit4] 2> 275542 T1028 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/control/data/index/
[junit4] 2> 275542 T1028 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 275543 T1028 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/control/data/index
[junit4] 2> 275543 T1028 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=42, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=99.7998046875, floorSegmentMB=0.447265625, forceMergeDeletesPctAllowed=18.80048159956596, segmentsPerTier=47.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 275545 T1028 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 275546 T1028 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 275547 T1028 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 275547 T1028 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 275547 T1028 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 275547 T1028 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 275548 T1028 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 275548 T1028 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 275548 T1028 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 275548 T1028 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 275548 T1028 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 275548 T1028 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 275549 T1028 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 275549 T1028 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 275549 T1028 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 275549 T1028 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 275549 T1028 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 275551 T1028 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 275552 T1028 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 275552 T1028 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 275552 T1028 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=21, maxMergeAtOnceExplicit=42, maxMergedSegmentMB=98.671875, floorSegmentMB=0.86328125, forceMergeDeletesPctAllowed=2.4717017862115274, segmentsPerTier=28.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.38663518126249885
[junit4] 2> 275553 T1028 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 275554 T1028 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 275554 T1028 oass.SolrIndexSearcher.<init> Opening Searcher@314a5e5f main
[junit4] 2> 275555 T1029 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@314a5e5f main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 275555 T1028 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 275556 T1028 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49494 collection:control_collection shard:shard1
[junit4] 2> 275556 T1028 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 275561 T1028 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 275562 T1028 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 275563 T1028 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 275563 T1028 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49494/collection1/
[junit4] 2> 275563 T1028 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 275563 T1028 oasc.SyncStrategy.syncToMe http://127.0.0.1:49494/collection1/ has no replicas
[junit4] 2> 275563 T1028 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49494/collection1/ shard1
[junit4] 2> 275563 T1028 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 276368 T1026 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 276372 T1025 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> 276418 T1028 oasc.ZkController.register We are http://127.0.0.1:49494/collection1/ and leader is http://127.0.0.1:49494/collection1/
[junit4] 2> 276419 T1028 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49494
[junit4] 2> 276419 T1028 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 276419 T1028 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 276419 T1028 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 276421 T1028 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 276422 T1003 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 276422 T1003 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 276424 T1003 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 276425 T1032 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@573c15e5 name:ZooKeeperConnection Watcher:127.0.0.1:32843/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 276425 T1003 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 276426 T1003 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 276427 T1003 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 276486 T1003 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 276496 T1003 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57628
[junit4] 2> 276496 T1003 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 276497 T1003 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 276497 T1003 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383394566497
[junit4] 2> 276497 T1003 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383394566497/'
[junit4] 2> 276506 T1003 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383394566497/solr.xml
[junit4] 2> 276513 T1003 oasc.CoreContainer.<init> New CoreContainer 2357652
[junit4] 2> 276513 T1003 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383394566497/]
[junit4] 2> 276514 T1003 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 240000
[junit4] 2> 276514 T1003 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 276514 T1003 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 276514 T1003 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 276514 T1003 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 276515 T1003 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 276515 T1003 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 276515 T1003 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 276515 T1003 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 276516 T1003 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 276516 T1003 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 276517 T1003 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:32843/solr
[junit4] 2> 276517 T1003 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 276517 T1003 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 276519 T1043 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@21ddbba3 name:ZooKeeperConnection Watcher:127.0.0.1:32843 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 276520 T1003 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 276522 T1003 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 276529 T1045 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3cadd6a2 name:ZooKeeperConnection Watcher:127.0.0.1:32843/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 276530 T1003 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 276549 T1003 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 277551 T1003 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57628_
[junit4] 2> 277552 T1003 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57628_
[junit4] 2> 277555 T1032 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 277555 T1045 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 277555 T1025 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 277558 T1046 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 277558 T1046 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 277559 T1046 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 277875 T1026 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 277876 T1026 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:49494",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49494_",
[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> 277879 T1026 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:57628",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:57628_",
[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> 277879 T1026 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2]
[junit4] 2> 277879 T1026 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 277881 T1025 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> 277881 T1032 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> 277881 T1045 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> 278559 T1046 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 278559 T1046 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383394566497/collection1
[junit4] 2> 278559 T1046 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 278560 T1046 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 278560 T1046 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 278561 T1046 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383394566497/collection1/'
[junit4] 2> 278561 T1046 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383394566497/collection1/lib/classes/' to classloader
[junit4] 2> 278561 T1046 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383394566497/collection1/lib/README' to classloader
[junit4] 2> 278575 T1046 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 278591 T1046 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 278592 T1046 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 278596 T1046 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 278701 T1046 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 278710 T1046 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 278711 T1046 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 278719 T1046 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 278721 T1046 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 278723 T1046 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 278723 T1046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 278724 T1046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 278724 T1046 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 278724 T1046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 278725 T1046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 278725 T1046 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 278725 T1046 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty1-1383394566497/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/jetty1/
[junit4] 2> 278725 T1046 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4503cc23
[junit4] 2> 278726 T1046 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/jetty1
[junit4] 2> 278726 T1046 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/jetty1/index/
[junit4] 2> 278726 T1046 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 278726 T1046 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/jetty1/index
[junit4] 2> 278727 T1046 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=42, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=99.7998046875, floorSegmentMB=0.447265625, forceMergeDeletesPctAllowed=18.80048159956596, segmentsPerTier=47.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 278730 T1046 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 278730 T1046 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 278732 T1046 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 278732 T1046 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 278732 T1046 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 278732 T1046 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 278732 T1046 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 278732 T1046 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 278733 T1046 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 278733 T1046 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 278733 T1046 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 278733 T1046 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 278733 T1046 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 278733 T1046 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 278734 T1046 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 278734 T1046 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 278734 T1046 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 278735 T1046 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 278736 T1046 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 278736 T1046 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 278737 T1046 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=21, maxMergeAtOnceExplicit=42, maxMergedSegmentMB=98.671875, floorSegmentMB=0.86328125, forceMergeDeletesPctAllowed=2.4717017862115274, segmentsPerTier=28.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.38663518126249885
[junit4] 2> 278737 T1046 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 278738 T1046 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 278738 T1046 oass.SolrIndexSearcher.<init> Opening Searcher@28315b4 main
[junit4] 2> 278740 T1047 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@28315b4 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 278740 T1046 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 278741 T1046 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57628 collection:collection1 shard:shard2
[junit4] 2> 278742 T1046 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 278746 T1046 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 278747 T1046 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 278748 T1046 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 278748 T1046 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57628/collection1/
[junit4] 2> 278748 T1046 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 278748 T1046 oasc.SyncStrategy.syncToMe http://127.0.0.1:57628/collection1/ has no replicas
[junit4] 2> 278748 T1046 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57628/collection1/ shard2
[junit4] 2> 278748 T1046 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 279385 T1026 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 279391 T1032 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> 279391 T1045 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> 279391 T1025 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> 279403 T1046 oasc.ZkController.register We are http://127.0.0.1:57628/collection1/ and leader is http://127.0.0.1:57628/collection1/
[junit4] 2> 279403 T1046 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57628
[junit4] 2> 279403 T1046 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 279403 T1046 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 279404 T1046 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 279405 T1046 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 279406 T1003 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 279406 T1003 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 279459 T1003 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 279460 T1003 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52895
[junit4] 2> 279461 T1003 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 279461 T1003 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 279462 T1003 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383394569475
[junit4] 2> 279462 T1003 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383394569475/'
[junit4] 2> 279470 T1003 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383394569475/solr.xml
[junit4] 2> 279477 T1003 oasc.CoreContainer.<init> New CoreContainer 815497378
[junit4] 2> 279477 T1003 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383394569475/]
[junit4] 2> 279477 T1003 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 240000
[junit4] 2> 279478 T1003 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 279478 T1003 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 279478 T1003 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 279478 T1003 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 279478 T1003 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 279478 T1003 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 279479 T1003 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 279479 T1003 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 279480 T1003 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 279480 T1003 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 279480 T1003 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:32843/solr
[junit4] 2> 279480 T1003 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 279481 T1003 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 279483 T1059 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@757235a5 name:ZooKeeperConnection Watcher:127.0.0.1:32843 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 279483 T1003 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 279485 T1003 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 279487 T1061 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3b465171 name:ZooKeeperConnection Watcher:127.0.0.1:32843/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 279487 T1003 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 279489 T1003 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 280491 T1003 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52895_
[junit4] 2> 280493 T1003 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52895_
[junit4] 2> 280495 T1032 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 280495 T1025 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 280496 T1045 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 280496 T1061 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 280499 T1062 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 280499 T1062 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 280500 T1062 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 280895 T1026 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 280896 T1026 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:57628",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:57628_",
[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_node1"}
[junit4] 2> 280900 T1026 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:52895",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52895_",
[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> 280901 T1026 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 280901 T1026 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 280903 T1025 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> 280903 T1061 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> 280903 T1045 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> 280903 T1032 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> 281500 T1062 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 281500 T1062 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383394569475/collection1
[junit4] 2> 281500 T1062 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 281501 T1062 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 281501 T1062 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 281502 T1062 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383394569475/collection1/'
[junit4] 2> 281502 T1062 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383394569475/collection1/lib/classes/' to classloader
[junit4] 2> 281502 T1062 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383394569475/collection1/lib/README' to classloader
[junit4] 2> 281526 T1062 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 281534 T1062 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 281535 T1062 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 281539 T1062 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 281655 T1062 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 281658 T1062 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 281660 T1062 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 281668 T1062 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 281670 T1062 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 281671 T1062 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 281672 T1062 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 281673 T1062 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 281673 T1062 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 281673 T1062 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 281673 T1062 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 281674 T1062 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 281674 T1062 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty2-1383394569475/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/jetty2/
[junit4] 2> 281674 T1062 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4503cc23
[junit4] 2> 281674 T1062 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/jetty2
[junit4] 2> 281674 T1062 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/jetty2/index/
[junit4] 2> 281675 T1062 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 281675 T1062 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/jetty2/index
[junit4] 2> 281675 T1062 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=42, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=99.7998046875, floorSegmentMB=0.447265625, forceMergeDeletesPctAllowed=18.80048159956596, segmentsPerTier=47.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 281678 T1062 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 281678 T1062 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 281680 T1062 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 281680 T1062 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 281680 T1062 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 281680 T1062 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 281680 T1062 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 281680 T1062 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 281681 T1062 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 281681 T1062 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 281681 T1062 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 281681 T1062 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 281681 T1062 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 281681 T1062 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 281682 T1062 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 281682 T1062 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 281682 T1062 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 281683 T1062 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 281684 T1062 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 281684 T1062 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 281685 T1062 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=21, maxMergeAtOnceExplicit=42, maxMergedSegmentMB=98.671875, floorSegmentMB=0.86328125, forceMergeDeletesPctAllowed=2.4717017862115274, segmentsPerTier=28.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.38663518126249885
[junit4] 2> 281686 T1062 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 281686 T1062 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 281686 T1062 oass.SolrIndexSearcher.<init> Opening Searcher@59b437 main
[junit4] 2> 281688 T1063 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@59b437 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 281689 T1062 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 281689 T1062 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52895 collection:collection1 shard:shard1
[junit4] 2> 281690 T1062 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 281694 T1062 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 281695 T1062 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 281695 T1062 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 281695 T1062 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52895/collection1/
[junit4] 2> 281695 T1062 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 281695 T1062 oasc.SyncStrategy.syncToMe http://127.0.0.1:52895/collection1/ has no replicas
[junit4] 2> 281696 T1062 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52895/collection1/ shard1
[junit4] 2> 281696 T1062 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 282409 T1026 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 282419 T1061 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> 282419 T1032 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> 282419 T1045 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> 282420 T1025 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> 282451 T1062 oasc.ZkController.register We are http://127.0.0.1:52895/collection1/ and leader is http://127.0.0.1:52895/collection1/
[junit4] 2> 282451 T1062 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52895
[junit4] 2> 282451 T1062 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 282451 T1062 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 282452 T1062 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 282454 T1062 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 282455 T1003 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 282455 T1003 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 282513 T1003 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 282515 T1003 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:46344
[junit4] 2> 282515 T1003 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 282516 T1003 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 282516 T1003 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383394572525
[junit4] 2> 282516 T1003 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383394572525/'
[junit4] 2> 282529 T1003 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383394572525/solr.xml
[junit4] 2> 282548 T1003 oasc.CoreContainer.<init> New CoreContainer 1043122063
[junit4] 2> 282549 T1003 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383394572525/]
[junit4] 2> 282549 T1003 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 240000
[junit4] 2> 282550 T1003 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 282550 T1003 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 282550 T1003 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 282551 T1003 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 282551 T1003 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 282551 T1003 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 282552 T1003 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 282552 T1003 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 282554 T1003 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 282554 T1003 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 282555 T1003 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:32843/solr
[junit4] 2> 282555 T1003 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 282556 T1003 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 282559 T1075 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c564bf2 name:ZooKeeperConnection Watcher:127.0.0.1:32843 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 282559 T1003 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 282563 T1003 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 282565 T1077 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d0f458 name:ZooKeeperConnection Watcher:127.0.0.1:32843/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 282565 T1003 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 282572 T1003 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 283576 T1003 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46344_
[junit4] 2> 283577 T1003 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:46344_
[junit4] 2> 283582 T1045 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 283582 T1061 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 283582 T1077 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 283582 T1032 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 283582 T1025 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 283587 T1078 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 283587 T1078 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 283589 T1078 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 283928 T1026 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 283929 T1026 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:52895",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:52895_",
[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_node2"}
[junit4] 2> 283931 T1026 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:46344",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:46344_",
[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> 283932 T1026 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4] 2> 283932 T1026 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 283935 T1045 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> 283935 T1032 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> 283935 T1077 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> 283935 T1061 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> 283935 T1025 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> 284589 T1078 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 284589 T1078 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383394572525/collection1
[junit4] 2> 284590 T1078 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 284591 T1078 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 284591 T1078 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 284593 T1078 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383394572525/collection1/'
[junit4] 2> 284594 T1078 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383394572525/collection1/lib/classes/' to classloader
[junit4] 2> 284594 T1078 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383394572525/collection1/lib/README' to classloader
[junit4] 2> 284615 T1078 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4] 2> 284622 T1078 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 284624 T1078 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 284641 T1078 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 284759 T1078 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 284762 T1078 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 284763 T1078 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 284771 T1078 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 284772 T1078 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 284774 T1078 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 284775 T1078 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 284775 T1078 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 284775 T1078 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 284776 T1078 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 284776 T1078 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 284776 T1078 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 284776 T1078 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty3-1383394572525/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/jetty3/
[junit4] 2> 284776 T1078 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4503cc23
[junit4] 2> 284777 T1078 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/jetty3
[junit4] 2> 284777 T1078 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/jetty3/index/
[junit4] 2> 284777 T1078 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 284777 T1078 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/jetty3/index
[junit4] 2> 284777 T1078 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=42, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=99.7998046875, floorSegmentMB=0.447265625, forceMergeDeletesPctAllowed=18.80048159956596, segmentsPerTier=47.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
[junit4] 2> 284780 T1078 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/jetty3/index,segFN=segments_1,generation=1}
[junit4] 2> 284780 T1078 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 284782 T1078 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 284782 T1078 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 284782 T1078 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 284782 T1078 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 284782 T1078 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 284782 T1078 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 284783 T1078 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 284783 T1078 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 284783 T1078 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 284783 T1078 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 284783 T1078 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 284783 T1078 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 284784 T1078 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 284784 T1078 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 284784 T1078 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 284785 T1078 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 284786 T1078 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 284786 T1078 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 284787 T1078 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=21, maxMergeAtOnceExplicit=42, maxMergedSegmentMB=98.671875, floorSegmentMB=0.86328125, forceMergeDeletesPctAllowed=2.4717017862115274, segmentsPerTier=28.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.38663518126249885
[junit4] 2> 284787 T1078 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-1383394563071/jetty3/index,segFN=segments_1,generation=1}
[junit4] 2> 284788 T1078 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 284788 T1078 oass.SolrIndexSearcher.<init> Opening Searcher@5ceaa48 main
[junit4] 2> 284791 T1079 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5ceaa48 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 284792 T1078 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 284792 T1078 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:46344 collection:collection1 shard:shard2
[junit4] 2> 284794 T1078 oasc.ZkController.register We are http://127.0.0.1:46344/collection1/ and leader is http://127.0.0.1:57628/collection1/
[junit4] 2> 284794 T1078 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:46344
[junit4] 2> 284795 T1078 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4] 2> 284795 T1078 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4] 2> ASYNC NEW_CORE C3906 name=collection1 org.apache.solr.core.SolrCore@57eddbc6 url=http://127.0.0.1:46344/collection1 node=127.0.0.1:46344_ C3906_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:46344, core=collection1, node_name=127.0.0.1:46344_}
[junit4] 2> 284795 T1080 C3906 P46344 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4] 2> 284795 T1078 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 284795 T1080 C3906 P46344 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4] 2> 284796 T1080 C3906 P46344 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4] 2> 284796 T1080 C3906 P46344 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 284796 T1003 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 284797 T1003 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 284798 T1041 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node3, state: recovering, checkLive: true, onlyIfLeader: true
[junit4] 2> 284880 T1003 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 284882 T1003 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:41909
[junit4] 2> 284883 T1003 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 284883 T1003 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 284884 T1003 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty4-1383394574866
[junit4] 2> 284884 T1003 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty4-1383394574866/'
[junit4] 2> 284892 T1003 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty4-1383394574866/solr.xml
[junit4] 2> 284899 T1003 oasc.CoreContainer.<init> New CoreContainer 1452022784
[junit4] 2> 284899 T1003 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeyNothingIsSafeTest-jetty4-1383394574866/]
[junit4] 2> 284899 T1003 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 240000
[junit4] 2> 284900 T1003 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 284900 T1003 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 284900 T1003 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 284900 T1003 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 284900 T1003 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 284901 T1003 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 284901 T1003 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 284901 T1003 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 284902 T1003 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 284902 T1003 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 284902 T1003 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:32843/solr
[junit4] 2> 284902 T1003 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 284903 T1003 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 284905 T1092 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6e0de6ad name:ZooKeeperConnection Watcher:127.0.0.1:32843 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 284906 T1003 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 284909 T1003 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 284911 T1094 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@426e5507 name:ZooKeeperConnection Watcher:127.0.0.1:32843/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 284911 T1003 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 284915 T1003 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 285439 T1026 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 285440 T1026 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:46344",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:46344_",
[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_node3"}
[junit4] 2> 285444 T1045 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> 285444 T1025 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> 285444 T1032 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConne
[...truncated too long message...]
"core":"collection1",
[junit4] 1> "base_url":"http://127.0.0.1:49494",
[junit4] 1> "node_name":"127.0.0.1:49494_"}
[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/90662146085552131-core_node1-n_0000000000 (0)
[junit4] 1> /solr/live_nodes (6)
[junit4] 1> /solr/live_nodes/127.0.0.1:37095_ (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:46344_ (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:49494_ (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:41909_ (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:52895_ (0)
[junit4] 1> /solr/live_nodes/127.0.0.1:37090_ (0)
[junit4] 1> /solr/overseer_elect (2)
[junit4] 1> /solr/overseer_elect/leader (0)
[junit4] 1> DATA:
[junit4] 1> {"id":"90662146085552131-127.0.0.1:49494_-n_0000000000"}
[junit4] 1> /solr/overseer_elect/election (6)
[junit4] 1> /solr/overseer_elect/election/90662146085552138-127.0.0.1:46344_-n_0000000003 (0)
[junit4] 1> /solr/overseer_elect/election/90662146085552147-127.0.0.1:52895_-n_0000000009 (0)
[junit4] 1> /solr/overseer_elect/election/90662146085552142-127.0.0.1:37090_-n_0000000005 (0)
[junit4] 1> /solr/overseer_elect/election/90662146085552146-127.0.0.1:37095_-n_0000000007 (0)
[junit4] 1> /solr/overseer_elect/election/90662146085552148-127.0.0.1:41909_-n_0000000008 (0)
[junit4] 1> /solr/overseer_elect/election/90662146085552131-127.0.0.1:49494_-n_0000000000 (0)
[junit4] 1> /solr/clusterstate.json (0)
[junit4] 1> DATA:
[junit4] 1> {
[junit4] 1> "control_collection":{
[junit4] 1> "replicationFactor":"1",
[junit4] 1> "shards":{"shard1":{
[junit4] 1> "range":"80000000-7fffffff",
[junit4] 1> "state":"active",
[junit4] 1> "replicas":{"core_node1":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:49494",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:49494_",
[junit4] 1> "leader":"true"}}}},
[junit4] 1> "router":{"name":"compositeId"},
[junit4] 1> "autoCreated":"true",
[junit4] 1> "maxShardsPerNode":"1"},
[junit4] 1> "collection1":{
[junit4] 1> "replicationFactor":"1",
[junit4] 1> "shards":{
[junit4] 1> "shard1":{
[junit4] 1> "range":"80000000-ffffffff",
[junit4] 1> "state":"active",
[junit4] 1> "replicas":{
[junit4] 1> "core_node2":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:52895",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:52895_"},
[junit4] 1> "core_node4":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:41909",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:41909_",
[junit4] 1> "leader":"true"},
[junit4] 1> "core_node6":{
[junit4] 1> "state":"down",
[junit4] 1> "base_url":"http://127.0.0.1:52863",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:52863_"}}},
[junit4] 1> "shard2":{
[junit4] 1> "range":"0-7fffffff",
[junit4] 1> "state":"active",
[junit4] 1> "replicas":{
[junit4] 1> "core_node1":{
[junit4] 1> "state":"down",
[junit4] 1> "base_url":"http://127.0.0.1:57628",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:57628_"},
[junit4] 1> "core_node3":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:46344",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:46344_",
[junit4] 1> "leader":"true"},
[junit4] 1> "core_node5":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:37090",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:37090_"},
[junit4] 1> "core_node7":{
[junit4] 1> "state":"active",
[junit4] 1> "base_url":"http://127.0.0.1:37095",
[junit4] 1> "core":"collection1",
[junit4] 1> "node_name":"127.0.0.1:37095_"}}}},
[junit4] 1> "router":{"name":"compositeId"},
[junit4] 1> "autoCreated":"true",
[junit4] 1> "maxShardsPerNode":"1"}}
[junit4] 1>
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeyNothingIsSafeTest -Dtests.method=testDistribSearch -Dtests.seed=476E806C412C2E3 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=hr_HR -Dtests.timezone=SystemV/AST4 -Dtests.file.encoding=UTF-8
[junit4] FAILURE 91.8s J1 | ChaosMonkeyNothingIsSafeTest.testDistribSearch <<<
[junit4] > Throwable #1: java.lang.AssertionError: document count mismatch. control=118 sum(shards)=117 cloudClient=117
[junit4] > at __randomizedtesting.SeedInfo.seed([476E806C412C2E3:8590661EB34DA2DF]: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:724)
[junit4] 2> 364771 T1003 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> 91775 T1002 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 3 leaked thread(s).
[junit4] 2> 364794 T1112 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 365916 T1147 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: test params are: codec=Lucene45, sim=DefaultSimilarity, locale=hr_HR, timezone=SystemV/AST4
[junit4] 2> NOTE: Linux 3.8.0-32-generic amd64/Oracle Corporation 1.8.0-ea (64-bit)/cpus=8,threads=6,free=93698664,total=212557824
[junit4] 2> NOTE: All tests run in this JVM: [TestZkChroot, AddSchemaFieldsUpdateProcessorFactoryTest, TestHashPartitioner, UniqFieldsUpdateProcessorFactoryTest, TestNonNRTOpen, TestNumberUtils, TestSolrCoreProperties, PreAnalyzedUpdateProcessorTest, TermVectorComponentDistributedTest, IndexSchemaRuntimeFieldTest, TestDefaultSearchFieldResource, PrimUtilsTest, TestComponentsName, TestRTGBase, ShardRoutingCustomTest, TestFuzzyAnalyzedSuggestions, TestCloudManagedSchema, RequiredFieldsTest, SimplePostToolTest, TestAddFieldRealTimeGet, DocValuesMissingTest, BlockCacheTest, TestAnalyzedSuggestions, SolrCmdDistributorTest, TestLazyCores, CoreMergeIndexesAdminHandlerTest, CollectionsAPIDistributedZkTest, TestXIncludeConfig, DefaultValueUpdateProcessorTest, TestFiltering, SuggesterWFSTTest, TestBinaryField, TestIBSimilarityFactory, StandardRequestHandlerTest, TestPhraseSuggestions, TestUniqueKeyFieldResource, QueryResultKeyTest, NumericFieldsTest, TestIndexSearcher, TestCollationField, TestCSVResponseWriter, OpenCloseCoreStressTest, DisMaxRequestHandlerTest, DateFieldTest, HdfsLockFactoryTest, TestClassNameShortening, JSONWriterTest, TestStressReorder, PingRequestHandlerTest, NoCacheHeaderTest, TestStressLucene, SpellingQueryConverterTest, HdfsSyncSliceTest, TestSchemaSimilarityResource, TestRandomFaceting, TestFastOutputStream, CoreContainerCoreInitFailuresTest, ChaosMonkeyNothingIsSafeTest]
[junit4] Completed on J1 in 93.05s, 1 test, 1 failure <<< FAILURES!
[...truncated 668 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:421: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:401: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:471: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1259: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:902: There were test failures: 332 suites, 1464 tests, 1 failure, 41 ignored (6 assumptions)
Total time: 39 minutes 29 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.8.0-ea-b109 -XX:-UseCompressedOops -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure