You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/10/25 06:45:03 UTC
[JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.8.0-ea-b109) - Build #
7935 - Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/7935/
Java: 64bit/jdk1.8.0-ea-b109 -XX:+UseCompressedOops -XX:+UseParallelGC
2 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.testDistribSearch
Error Message:
shard1 is not consistent. Got 149 from http://127.0.0.1:54520/collection1lastClient and got 137 from http://127.0.0.1:41072/collection1
Stack Trace:
java.lang.AssertionError: shard1 is not consistent. Got 149 from http://127.0.0.1:54520/collection1lastClient and got 137 from http://127.0.0.1:41072/collection1
at __randomizedtesting.SeedInfo.seed([F6B0240A04D52166:7756AA12738A415A]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1148)
at org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.doTest(ChaosMonkeySafeLeaderTest.java:135)
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)
REGRESSION: org.apache.solr.handler.TestReplicationHandler.doTestIndexAndConfigAliasReplication
Error Message:
timed out waiting for collection1 startAt time to exceed: Fri Oct 25 12:40:14 CST 2013
Stack Trace:
java.lang.AssertionError: timed out waiting for collection1 startAt time to exceed: Fri Oct 25 12:40:14 CST 2013
at __randomizedtesting.SeedInfo.seed([F6B0240A04D52166:1C3CA52C23D8E80]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.handler.TestReplicationHandler.watchCoreStartAt(TestReplicationHandler.java:1515)
at org.apache.solr.handler.TestReplicationHandler.doTestIndexAndConfigAliasReplication(TestReplicationHandler.java:1264)
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 10384 lines...]
[junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
[junit4] 2> 453018 T2328 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 453020 T2328 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-ChaosMonkeySafeLeaderTest-1382675815208
[junit4] 2> 453021 T2328 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 453021 T2329 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 453121 T2328 oasc.ZkTestServer.run start zk server on port:45166
[junit4] 2> 453123 T2328 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 453360 T2335 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@dab7afd name:ZooKeeperConnection Watcher:127.0.0.1:45166 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 453361 T2328 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 453361 T2328 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 453369 T2328 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 453371 T2337 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2080db66 name:ZooKeeperConnection Watcher:127.0.0.1:45166/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 453372 T2328 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 453372 T2328 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 453374 T2328 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 453378 T2328 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 453380 T2328 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 453383 T2328 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 453384 T2328 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 453443 T2328 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 453444 T2328 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 453448 T2328 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 453449 T2328 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 453451 T2328 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 453452 T2328 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 453454 T2328 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 453454 T2328 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 453456 T2328 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 453457 T2328 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 453459 T2328 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 453459 T2328 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 453461 T2328 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 453462 T2328 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 453464 T2328 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 453465 T2328 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 453467 T2328 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 453468 T2328 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 453522 T2328 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 453527 T2328 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53788
[junit4] 2> 453527 T2328 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 453527 T2328 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 453528 T2328 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1382675815657
[junit4] 2> 453528 T2328 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1382675815657/'
[junit4] 2> 453536 T2328 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1382675815657/solr.xml
[junit4] 2> 453542 T2328 oasc.CoreContainer.<init> New CoreContainer 2027570934
[junit4] 2> 453543 T2328 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1382675815657/]
[junit4] 2> 453543 T2328 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 453543 T2328 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 453544 T2328 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 453544 T2328 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 453544 T2328 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 453544 T2328 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 453544 T2328 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 453544 T2328 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 453545 T2328 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 453546 T2328 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 453546 T2328 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 453546 T2328 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:45166/solr
[junit4] 2> 453547 T2328 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 453547 T2328 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 453550 T2348 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2fd32576 name:ZooKeeperConnection Watcher:127.0.0.1:45166 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 453550 T2328 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 453552 T2328 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 453552 T2350 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5c48e16b name:ZooKeeperConnection Watcher:127.0.0.1:45166/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 453553 T2328 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 453553 T2328 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 453556 T2328 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 453557 T2328 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 453558 T2328 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53788_
[junit4] 2> 453559 T2328 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53788_
[junit4] 2> 453560 T2328 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 453563 T2328 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 453565 T2328 oasc.Overseer.start Overseer (id=90615042225537027-127.0.0.1:53788_-n_0000000000) starting
[junit4] 2> 453566 T2328 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 453569 T2352 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 453569 T2328 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 453571 T2328 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 453571 T1092 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 453572 T2328 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 453574 T2351 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 453575 T2353 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 453575 T2353 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 453579 T2353 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 455076 T2351 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 455077 T2351 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:53788",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:53788_",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 455077 T2351 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 455077 T2351 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 455162 T2350 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> 455181 T1100 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 455579 T2353 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 455579 T2353 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1382675815657/collection1
[junit4] 2> 455580 T2353 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 455580 T2353 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 455580 T2353 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 455581 T2353 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1382675815657/collection1/'
[junit4] 2> 455581 T2353 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1382675815657/collection1/lib/classes/' to classloader
[junit4] 2> 455582 T2353 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1382675815657/collection1/lib/README' to classloader
[junit4] 2> 455594 T2353 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 455613 T2353 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 455614 T2353 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 455618 T2353 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 455705 T2353 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 455705 T2353 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 455705 T2353 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 455709 T2353 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 455710 T2353 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 455717 T2353 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 455719 T2353 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 455721 T2353 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 455722 T2353 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 455722 T2353 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 455722 T2353 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 455723 T2353 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 455723 T2353 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 455723 T2353 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 455729 T2353 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1382675815657/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/control/data/
[junit4] 2> 455729 T2353 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@54f27016
[junit4] 2> 455730 T2353 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/control/data
[junit4] 2> 455730 T2353 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/control/data/index/
[junit4] 2> 455730 T2353 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 455730 T2353 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/control/data/index
[junit4] 2> 455731 T2353 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=36, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=49.482421875, floorSegmentMB=1.9482421875, forceMergeDeletesPctAllowed=24.229517411551633, segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.47487349731788686
[junit4] 2> 455733 T2353 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 455733 T2353 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 455734 T2353 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 455735 T2353 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 455735 T2353 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 455735 T2353 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 455735 T2353 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 455735 T2353 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 455736 T2353 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 455736 T2353 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 455736 T2353 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 455737 T2353 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 455737 T2353 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 455737 T2353 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 455737 T2353 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 455738 T2353 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 455738 T2353 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 455739 T2353 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 455740 T2353 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 455740 T2353 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 455741 T2353 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=12, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6045867477038233]
[junit4] 2> 455742 T2353 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 455742 T2353 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 455742 T2353 oass.SolrIndexSearcher.<init> Opening Searcher@14f5fed8 main
[junit4] 2> 455743 T2354 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@14f5fed8 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 455744 T2353 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 455744 T2353 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53788 collection:control_collection shard:shard1
[junit4] 2> 455745 T2353 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 455749 T2353 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 455750 T2353 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 455751 T2353 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 455751 T2353 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53788/collection1/
[junit4] 2> 455751 T2353 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 455751 T2353 oasc.SyncStrategy.syncToMe http://127.0.0.1:53788/collection1/ has no replicas
[junit4] 2> 455751 T2353 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53788/collection1/ shard1
[junit4] 2> 455751 T2353 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 456664 T2351 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 456669 T2350 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> 456706 T2353 oasc.ZkController.register We are http://127.0.0.1:53788/collection1/ and leader is http://127.0.0.1:53788/collection1/
[junit4] 2> 456707 T2353 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53788
[junit4] 2> 456707 T2353 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 456707 T2353 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 456707 T2353 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 456739 T2353 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 456740 T2328 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 456740 T2328 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 456741 T2328 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 456743 T2357 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@688ace3f name:ZooKeeperConnection Watcher:127.0.0.1:45166/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 456743 T2328 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 456744 T2328 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 456746 T2328 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 456791 T1108 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 456797 T2328 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 456798 T2328 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:59938
[junit4] 2> 456799 T2328 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 456799 T2328 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 456800 T2328 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1382675818933
[junit4] 2> 456800 T2328 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1382675818933/'
[junit4] 2> 456814 T2328 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1382675818933/solr.xml
[junit4] 2> 456819 T2328 oasc.CoreContainer.<init> New CoreContainer 236189889
[junit4] 2> 456820 T2328 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1382675818933/]
[junit4] 2> 456820 T2328 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 456820 T2328 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 456820 T2328 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 456821 T2328 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 456821 T2328 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 456821 T2328 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 456821 T2328 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 456821 T2328 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 456822 T2328 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 456822 T2328 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 456823 T2328 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 456823 T2328 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:45166/solr
[junit4] 2> 456823 T2328 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 456824 T2328 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 456825 T2368 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7ff55d4e name:ZooKeeperConnection Watcher:127.0.0.1:45166 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 456826 T2328 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 456828 T2328 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 456829 T2370 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@54ad687e name:ZooKeeperConnection Watcher:127.0.0.1:45166/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 456829 T2328 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 456831 T2328 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 457833 T2328 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59938_
[junit4] 2> 457834 T2328 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:59938_
[junit4] 2> 457835 T2357 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 457836 T2350 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 457835 T2370 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 457838 T2371 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 457838 T2371 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 457839 T2371 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 458172 T2351 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 458173 T2351 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:53788",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:53788_",
[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> 458175 T2351 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:59938",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:59938_",
[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":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 458176 T2351 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 458176 T2351 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 458178 T2350 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> 458178 T2370 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> 458178 T2357 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> 458500 T1116 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 458839 T2371 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 458839 T2371 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1382675818933/collection1
[junit4] 2> 458839 T2371 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 458840 T2371 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 458840 T2371 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 458841 T2371 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1382675818933/collection1/'
[junit4] 2> 458841 T2371 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1382675818933/collection1/lib/classes/' to classloader
[junit4] 2> 458841 T2371 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1382675818933/collection1/lib/README' to classloader
[junit4] 2> 458854 T2371 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 458861 T2371 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 458862 T2371 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 458866 T2371 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 458962 T2371 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 458962 T2371 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 458962 T2371 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 458967 T2371 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 458968 T2371 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 458978 T2371 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 458980 T2371 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 458982 T2371 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 458983 T2371 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 458983 T2371 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 458983 T2371 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 458984 T2371 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 458984 T2371 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 458985 T2371 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 458985 T2371 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1382675818933/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/jetty1/
[junit4] 2> 458985 T2371 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@54f27016
[junit4] 2> 458986 T2371 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/jetty1
[junit4] 2> 458986 T2371 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/jetty1/index/
[junit4] 2> 458986 T2371 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 458986 T2371 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/jetty1/index
[junit4] 2> 458987 T2371 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=36, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=49.482421875, floorSegmentMB=1.9482421875, forceMergeDeletesPctAllowed=24.229517411551633, segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.47487349731788686
[junit4] 2> 459007 T2371 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 459007 T2371 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 459009 T2371 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 459009 T2371 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 459009 T2371 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 459009 T2371 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 459009 T2371 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 459009 T2371 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 459010 T2371 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 459010 T2371 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 459010 T2371 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 459010 T2371 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 459011 T2371 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 459011 T2371 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 459011 T2371 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 459011 T2371 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 459011 T2371 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 459013 T2371 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 459014 T2371 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 459014 T2371 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 459014 T2371 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=12, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6045867477038233]
[junit4] 2> 459015 T2371 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 459015 T2371 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 459016 T2371 oass.SolrIndexSearcher.<init> Opening Searcher@152d0556 main
[junit4] 2> 459018 T2372 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@152d0556 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 459018 T2371 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 459019 T2371 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:59938 collection:collection1 shard:shard2
[junit4] 2> 459019 T2371 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 459023 T2371 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 459025 T2371 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 459025 T2371 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 459025 T2371 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:59938/collection1/
[junit4] 2> 459025 T2371 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 459025 T2371 oasc.SyncStrategy.syncToMe http://127.0.0.1:59938/collection1/ has no replicas
[junit4] 2> 459026 T2371 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:59938/collection1/ shard2
[junit4] 2> 459026 T2371 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 459682 T2351 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 459686 T2350 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> 459686 T2370 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> 459686 T2357 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> 459730 T2371 oasc.ZkController.register We are http://127.0.0.1:59938/collection1/ and leader is http://127.0.0.1:59938/collection1/
[junit4] 2> 459730 T2371 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:59938
[junit4] 2> 459730 T2371 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 459731 T2371 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 459731 T2371 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 459733 T2371 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 459733 T2328 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 459734 T2328 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 459824 T2328 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 459826 T2328 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:39995
[junit4] 2> 459826 T2328 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 459827 T2328 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 459828 T2328 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1382675821922
[junit4] 2> 459828 T2328 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1382675821922/'
[junit4] 2> 459840 T2328 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1382675821922/solr.xml
[junit4] 2> 459848 T2328 oasc.CoreContainer.<init> New CoreContainer 575620830
[junit4] 2> 459848 T2328 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1382675821922/]
[junit4] 2> 459849 T2328 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 459849 T2328 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 459849 T2328 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 459849 T2328 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 459850 T2328 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 459850 T2328 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 459850 T2328 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 459851 T2328 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 459851 T2328 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 459853 T2328 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 459853 T2328 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 459854 T2328 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:45166/solr
[junit4] 2> 459854 T2328 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 459855 T2328 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 459856 T2384 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@49a4db76 name:ZooKeeperConnection Watcher:127.0.0.1:45166 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 459856 T2328 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 459858 T2328 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 459863 T2386 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@cc1e47a name:ZooKeeperConnection Watcher:127.0.0.1:45166/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 459863 T2328 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 459867 T2328 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 460115 T1124 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 460869 T2328 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39995_
[junit4] 2> 460871 T2328 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:39995_
[junit4] 2> 460872 T2357 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 460872 T2386 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 460872 T2370 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 460872 T2350 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 460875 T2387 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 460875 T2387 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 460876 T2387 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 461191 T2351 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 461192 T2351 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:59938",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:59938_",
[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":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 461194 T2351 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:39995",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:39995_",
[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":"3",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 461194 T2351 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 461194 T2351 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 461196 T2357 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> 461196 T2386 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> 461196 T2350 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> 461197 T2370 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> 461824 T1132 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 461877 T2387 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 461877 T2387 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1382675821922/collection1
[junit4] 2> 461877 T2387 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 461877 T2387 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 461877 T2387 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 461878 T2387 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1382675821922/collection1/'
[junit4] 2> 461879 T2387 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1382675821922/collection1/lib/classes/' to classloader
[junit4] 2> 461879 T2387 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1382675821922/collection1/lib/README' to classloader
[junit4] 2> 461891 T2387 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 461898 T2387 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 461900 T2387 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 461904 T2387 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 461984 T2387 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 461985 T2387 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 461985 T2387 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 461988 T2387 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 461989 T2387 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 461999 T2387 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 462000 T2387 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 462002 T2387 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 462002 T2387 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 462002 T2387 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 462002 T2387 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 462003 T2387 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 462003 T2387 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 462003 T2387 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 462004 T2387 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1382675821922/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/jetty2/
[junit4] 2> 462004 T2387 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@54f27016
[junit4] 2> 462004 T2387 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/jetty2
[junit4] 2> 462004 T2387 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/jetty2/index/
[junit4] 2> 462004 T2387 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 462005 T2387 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/jetty2/index
[junit4] 2> 462005 T2387 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=36, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=49.482421875, floorSegmentMB=1.9482421875, forceMergeDeletesPctAllowed=24.229517411551633, segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.47487349731788686
[junit4] 2> 462007 T2387 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 462007 T2387 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 462009 T2387 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 462009 T2387 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 462009 T2387 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 462009 T2387 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 462009 T2387 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 462009 T2387 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 462010 T2387 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 462010 T2387 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 462010 T2387 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 462010 T2387 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 462010 T2387 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 462010 T2387 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 462011 T2387 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 462011 T2387 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 462011 T2387 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 462012 T2387 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 462013 T2387 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 462013 T2387 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 462014 T2387 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=12, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6045867477038233]
[junit4] 2> 462014 T2387 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 462014 T2387 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 462015 T2387 oass.SolrIndexSearcher.<init> Opening Searcher@5758a717 main
[junit4] 2> 462016 T2388 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5758a717 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 462017 T2387 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 462017 T2387 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:39995 collection:collection1 shard:shard3
[junit4] 2> 462018 T2387 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 462022 T2387 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard3
[junit4] 2> 462024 T2387 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 462024 T2387 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 462024 T2387 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:39995/collection1/
[junit4] 2> 462024 T2387 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 462024 T2387 oasc.SyncStrategy.syncToMe http://127.0.0.1:39995/collection1/ has no replicas
[junit4] 2> 462024 T2387 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:39995/collection1/ shard3
[junit4] 2> 462024 T2387 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 462700 T2351 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 462704 T2357 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> 462704 T2386 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> 462704 T2370 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> 462704 T2350 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> 462729 T2387 oasc.ZkController.register We are http://127.0.0.1:39995/collection1/ and leader is http://127.0.0.1:39995/collection1/
[junit4] 2> 462729 T2387 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:39995
[junit4] 2> 462729 T2387 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 462730 T2387 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 462730 T2387 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 462731 T2387 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 462732 T2328 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4] 2> 462732 T2328 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 462784 T2328 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 462785 T2328 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50096
[junit4] 2> 462786 T2328 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 462786 T2328 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 462787 T2328 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1382675824919
[junit4] 2> 462787 T2328 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1382675824919/'
[junit4] 2> 462799 T2328 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1382675824919/solr.xml
[junit4] 2> 462805 T2328 oasc.CoreContainer.<init> New CoreContainer 2062574969
[junit4] 2> 462806 T2328 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1382675824919/]
[junit4] 2> 462806 T2328 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 462806 T2328 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 462806 T2328 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 462807 T2328 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 462807 T2328 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 462807 T2328 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 462807 T2328 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 462807 T2328 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 462808 T2328 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 462808 T2328 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 462809 T2328 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 462809 T2328 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:45166/solr
[junit4] 2> 462809 T2328 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 462810 T2328 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 462811 T2400 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6e1e4491 name:ZooKeeperConnection Watcher:127.0.0.1:45166 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 462811 T2328 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 462813 T2328 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 462813 T2402 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@72573600 name:ZooKeeperConnection Watcher:127.0.0.1:45166/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 462814 T2328 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 462816 T2328 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 463433 T1140 oasc.OverseerCollectionProcessor.run WARN Overseer cannot talk to ZK
[junit4] 2> 463818 T2328 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50096_
[junit4] 2> 463819 T2328 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50096_
[junit4] 2> 463820 T2357 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 463821 T2386 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 463821 T2370 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 463821 T2350 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 463821 T2402 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 463823 T2403 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 463823 T2403 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 463824 T2403 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 464207 T2351 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 464208 T2351 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:39995",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:39995_",
[junit4] 2> "shard":"shard3",
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 464212 T2351 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:50096",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:50096_",
[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":"3",
[junit4] 2> "core_node_name":"core_node3"}
[junit4] 2> 464212 T2351 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 464212 T2351 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 464214 T2357 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> 464214 T2370 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> 464214 T2350 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> 464214 T2402 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> 464214 T2386 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> 464824 T2403 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 464824 T2403 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1382675824919/collection1
[junit4] 2> 464824 T2403 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 464825 T2403 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 464825 T2403 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 464826 T2403 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1382675824919/collection1/'
[junit4] 2> 464827 T2403 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1382675824919/collection1/lib/classes/' to classloader
[junit4] 2> 464827 T2403 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1382675824919/collection1/lib/README' to classloader
[junit4] 2> 464840 T2403 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 464847 T2403 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 464847 T2403 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 464851 T2403 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 464939 T2403 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 464940 T2403 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 464940 T2403 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 464943 T2403 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 464944 T2403 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 464950 T2403 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 464952 T2403 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 464953 T2403 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 464954 T2403 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 464954 T2403 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 464954 T2403 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 464955 T2403 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 464955 T2403 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 464955 T2403 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 464955 T2403 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1382675824919/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/jetty3/
[junit4] 2> 464955 T2403 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@54f27016
[junit4] 2> 464956 T2403 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/jetty3
[junit4] 2> 464956 T2403 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/jetty3/index/
[junit4] 2> 464956 T2403 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 464956 T2403 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/jetty3/index
[junit4] 2> 464956 T2403 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=36, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=49.482421875, floorSegmentMB=1.9482421875, forceMergeDeletesPctAllowed=24.229517411551633, segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.47487349731788686
[junit4] 2> 464959 T2403 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382675815207/jetty3/index,segFN=segments_1,generation=1}
[junit4] 2> 464959 T2403 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 464961 T2403 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 464961 T2403 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 464961 T2403 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 464961 T2403 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 464961 T2403 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 464962 T2403 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 464962 T2403 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 464962 T2403 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 464962 T2403 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 464962 T2403 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 464963 T2403 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 464963 T2403 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 464963 T2403 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 464963 T2403 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 464963 T2403 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 464964 T2403 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 464965 T2403 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 464965 T2403 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 464966 T2403 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=12, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true,
[...truncated too long message...]
replication params={command=details} status=0 QTime=0
[junit4] 2> 685813 T3508 oash.SnapPuller.fetchLatestIndex ERROR Master at: http://127.0.0.1:55621/solr is not available. Index fetch failed. Exception: Server refused connection at: http://127.0.0.1:55621/solr
[junit4] 2> 685843 T3515 C682 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details} status=0 QTime=0
[junit4] 2> 685845 T3515 C682 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=backup&numberToKeep=1} status=0 QTime=1
[junit4] 2> 685845 T3528 oash.SnapShooter.createSnapshot Creating backup snapshot...
[junit4] 2> 686046 T3517 C682 oasc.SolrCore.execute [collection1] webapp=/solr path=/replication params={command=details} status=0 QTime=0
[junit4] 2> 686049 T2909 oas.SolrTestCaseJ4.tearDown ###Ending doTestBackup
[junit4] 2> 686069 T2909 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=356688306
[junit4] 2> 686070 T2909 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@59481359
[junit4] 2> 686070 T2909 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=492,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4] 2> 686070 T2909 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 686070 T2909 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 686071 T2909 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 686072 T2909 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 686072 T2909 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 686072 T2909 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1382676045442/master/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1382676045442/master/collection1/data;done=false>>]
[junit4] 2> 686072 T2909 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1382676045442/master/collection1/data
[junit4] 2> 686073 T2909 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1382676045442/master/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1382676045442/master/collection1/data/index;done=false>>]
[junit4] 2> 686073 T2909 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1382676045442/master/collection1/data/index
[junit4] 2> 686073 T2909 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 686145 T2909 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=964523589
[junit4] 2> 686145 T2909 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@3b877083
[junit4] 2> 686146 T2909 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4] 2> 686146 T2909 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 686147 T2909 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 686147 T2909 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 686148 T2909 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 686148 T2909 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 686148 T2909 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1382676045499/slave/collection1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1382676045499/slave/collection1/data/index;done=false>>]
[junit4] 2> 686149 T2909 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1382676045499/slave/collection1/data/index
[junit4] 2> 686149 T2909 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1382676045499/slave/collection1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1382676045499/slave/collection1/data;done=false>>]
[junit4] 2> 686149 T2909 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.handler.TestReplicationHandler$SolrInstance-1382676045499/slave/collection1/data
[junit4] 2> 686150 T2909 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
[junit4] 2> 686204 T2909 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene41, sim=DefaultSimilarity, locale=es_BO, timezone=CTT
[junit4] 2> NOTE: Linux 3.8.0-32-generic amd64/Oracle Corporation 1.8.0-ea (64-bit)/cpus=8,threads=1,free=208450952,total=373817344
[junit4] 2> NOTE: All tests run in this JVM: [HdfsBasicDistributedZk2Test, TestPerFieldSimilarity, PrimitiveFieldTypeTest, TestLMDirichletSimilarityFactory, TestSystemIdResolver, TestSolrXMLSerializer, ClusterStateUpdateTest, TestSurroundQueryParser, TestSolrQueryParserResource, URLClassifyProcessorTest, SolrTestCaseJ4Test, StressHdfsTest, TestPseudoReturnFields, TestFunctionQuery, LegacyHTMLStripCharFilterTest, TestSuggestSpellingConverter, DeleteShardTest, TestBadConfig, SliceStateTest, TestFaceting, HdfsDirectoryTest, AddSchemaFieldsUpdateProcessorFactoryTest, TestReversedWildcardFilterFactory, SchemaVersionSpecificBehaviorTest, TestTrie, SolrCoreTest, HdfsChaosMonkeySafeLeaderTest, TestAddFieldRealTimeGet, SearchHandlerTest, TestLFUCache, TestSearchPerf, SpatialFilterTest, DistributedSpellCheckComponentTest, TestQueryUtils, TermVectorComponentTest, UpdateParamsTest, HdfsSyncSliceTest, TestLuceneMatchVersion, TestCloudManagedSchemaAddField, TestPostingsSolrHighlighter, OverseerTest, AliasIntegrationTest, UnloadDistributedZkTest, SliceStateUpdateTest, TestFieldTypeResource, WordBreakSolrSpellCheckerTest, TestElisionMultitermQuery, CoreMergeIndexesAdminHandlerTest, TestDocSet, EchoParamsTest, MoreLikeThisHandlerTest, AnalysisAfterCoreReloadTest, TestSolrQueryParser, TestNoOpRegenerator, PeerSyncTest, ResourceLoaderTest, SampleTest, TestSolrDeletionPolicy1, TestCoreContainer, TestWriterPerf, LukeRequestHandlerTest, HdfsBasicDistributedZkTest, DocumentBuilderTest, CopyFieldTest, LeaderElectionTest, TestJmxMonitoredMap, TestStressVersions, TestMergePolicyConfig, TestSchemaSimilarityResource, TestSchemaNameResource, TestFieldTypeCollectionResource, ReturnFieldsTest, TestSolrXmlPersistor, SuggesterTest, SpellPossibilityIteratorTest, TestSort, BadComponentTest, SynonymTokenizerTest, TestManagedSchema, RecoveryZkTest, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, ShardRoutingTest, TestReplicationHandler]
[junit4] Completed on J0 in 57.54s, 14 tests, 1 failure, 1 skipped <<< FAILURES!
[...truncated 479 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:428: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:408: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:483: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1263: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:906: There were test failures: 328 suites, 1455 tests, 2 failures, 39 ignored (6 assumptions)
Total time: 35 minutes 49 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.8.0-ea-b109 -XX:+UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure
[JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.6.0_45) - Build # 7936
- Still Failing!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/7936/
Java: 64bit/jdk1.6.0_45 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
1 tests failed.
FAILED: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.testDistribSearch
Error Message:
shard2 is not consistent. Got 43 from http://127.0.0.1:45941/collection1lastClient and got 41 from http://127.0.0.1:58403/collection1
Stack Trace:
java.lang.AssertionError: shard2 is not consistent. Got 43 from http://127.0.0.1:45941/collection1lastClient and got 41 from http://127.0.0.1:58403/collection1
at __randomizedtesting.SeedInfo.seed([EEAB6C82211B36F0:6F4DE29A564456CC]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1148)
at org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.doTest(ChaosMonkeySafeLeaderTest.java:135)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:662)
Build Log:
[...truncated 9500 lines...]
[junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
[junit4] 2> 390638 T1352 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 390644 T1352 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-ChaosMonkeySafeLeaderTest-1382681347310
[junit4] 2> 390645 T1352 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 2> 390645 T1353 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 390745 T1352 oasc.ZkTestServer.run start zk server on port:48185
[junit4] 2> 390747 T1352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 390843 T1359 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@549440d6 name:ZooKeeperConnection Watcher:127.0.0.1:48185 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 390843 T1352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 390844 T1352 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 390851 T1352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 390852 T1361 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@337d9531 name:ZooKeeperConnection Watcher:127.0.0.1:48185/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 390852 T1352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 390853 T1352 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 390858 T1352 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 390863 T1352 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 390866 T1352 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 390874 T1352 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 390874 T1352 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 390881 T1352 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4] 2> 390881 T1352 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 390886 T1352 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 390887 T1352 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 390891 T1352 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 390892 T1352 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 390898 T1352 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 390898 T1352 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 390903 T1352 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 390903 T1352 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 390907 T1352 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 390908 T1352 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 390915 T1352 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 390916 T1352 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 390921 T1352 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 390921 T1352 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 390932 T1352 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 390933 T1352 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 391019 T1352 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 391023 T1352 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:48062
[junit4] 2> 391023 T1352 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 391024 T1352 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 391024 T1352 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1382681347605
[junit4] 2> 391025 T1352 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1382681347605/'
[junit4] 2> 391036 T1352 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1382681347605/solr.xml
[junit4] 2> 391083 T1352 oasc.CoreContainer.<init> New CoreContainer 2086819119
[junit4] 2> 391084 T1352 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1382681347605/]
[junit4] 2> 391085 T1352 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 391086 T1352 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 391086 T1352 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 391088 T1352 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 391089 T1352 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 391089 T1352 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 391090 T1352 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 391090 T1352 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 391091 T1352 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 391092 T1352 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 391093 T1352 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 391093 T1352 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:48185/solr
[junit4] 2> 391094 T1352 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 391095 T1352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 391096 T1372 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1bc6c075 name:ZooKeeperConnection Watcher:127.0.0.1:48185 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 391097 T1352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 391101 T1352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 391103 T1374 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@32e0147f name:ZooKeeperConnection Watcher:127.0.0.1:48185/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 391103 T1352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 391106 T1352 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 391112 T1352 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 391117 T1352 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 391120 T1352 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:48062_
[junit4] 2> 391125 T1352 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:48062_
[junit4] 2> 391137 T1352 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 391148 T1352 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 391154 T1352 oasc.Overseer.start Overseer (id=90615404777504771-127.0.0.1:48062_-n_0000000000) starting
[junit4] 2> 391160 T1352 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 391166 T1376 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 391167 T1352 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 391174 T1352 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 391177 T1352 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 391182 T1375 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 391185 T1377 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 391185 T1377 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 391187 T1377 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 392689 T1375 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 392690 T1375 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:48062",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:48062_",
[junit4] 2> "shard":null,
[junit4] 2> "shard_range":null,
[junit4] 2> "shard_state":"active",
[junit4] 2> "shard_parent":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 392690 T1375 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 392690 T1375 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 392699 T1374 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> 393187 T1377 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 393188 T1377 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1382681347605/collection1
[junit4] 2> 393188 T1377 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 393189 T1377 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 393190 T1377 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 393192 T1377 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1382681347605/collection1/'
[junit4] 2> 393193 T1377 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1382681347605/collection1/lib/classes/' to classloader
[junit4] 2> 393193 T1377 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1382681347605/collection1/lib/README' to classloader
[junit4] 2> 393246 T1377 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 393293 T1377 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 393305 T1377 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 393312 T1377 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 393860 T1377 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 393861 T1377 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 393862 T1377 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 393871 T1377 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 393874 T1377 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 393897 T1377 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 393902 T1377 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 393908 T1377 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 393910 T1377 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 393911 T1377 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 393911 T1377 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 393913 T1377 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 393914 T1377 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 393914 T1377 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 393914 T1377 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1382681347605/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/control/data/
[junit4] 2> 393915 T1377 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7a29450
[junit4] 2> 393915 T1377 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/control/data
[junit4] 2> 393916 T1377 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/control/data/index/
[junit4] 2> 393916 T1377 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 393916 T1377 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/control/data/index
[junit4] 2> 393917 T1377 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=73.33984375, floorSegmentMB=1.697265625, forceMergeDeletesPctAllowed=6.977258620560708, segmentsPerTier=39.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4710161330546846
[junit4] 2> 393919 T1377 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 393920 T1377 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 393923 T1377 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 393923 T1377 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 393923 T1377 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 393924 T1377 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 393924 T1377 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 393924 T1377 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 393925 T1377 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 393925 T1377 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 393925 T1377 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 393926 T1377 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 393926 T1377 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 393927 T1377 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 393927 T1377 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 393928 T1377 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 393928 T1377 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 393930 T1377 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 393934 T1377 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 393935 T1377 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 393935 T1377 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=27, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 393937 T1377 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 393937 T1377 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 393937 T1377 oass.SolrIndexSearcher.<init> Opening Searcher@37813079 main
[junit4] 2> 393941 T1378 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@37813079 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 393941 T1377 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 393941 T1377 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:48062 collection:control_collection shard:shard1
[junit4] 2> 393943 T1377 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 393963 T1377 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 393967 T1377 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 393967 T1377 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 393968 T1377 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:48062/collection1/
[junit4] 2> 393968 T1377 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 393968 T1377 oasc.SyncStrategy.syncToMe http://127.0.0.1:48062/collection1/ has no replicas
[junit4] 2> 393968 T1377 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:48062/collection1/ shard1
[junit4] 2> 393969 T1377 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 394210 T1375 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 394223 T1374 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> 394279 T1377 oasc.ZkController.register We are http://127.0.0.1:48062/collection1/ and leader is http://127.0.0.1:48062/collection1/
[junit4] 2> 394280 T1377 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:48062
[junit4] 2> 394280 T1377 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 394281 T1377 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 394281 T1377 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 394284 T1377 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 394286 T1352 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 394286 T1352 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 394289 T1352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 394290 T1381 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@54235c38 name:ZooKeeperConnection Watcher:127.0.0.1:48185/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 394291 T1352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 394294 T1352 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 394298 T1352 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4] 2> 394364 T1352 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 394367 T1352 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:45413
[junit4] 2> 394367 T1352 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 394368 T1352 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 394368 T1352 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1382681350964
[junit4] 2> 394369 T1352 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1382681350964/'
[junit4] 2> 394381 T1352 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1382681350964/solr.xml
[junit4] 2> 394430 T1352 oasc.CoreContainer.<init> New CoreContainer 883854022
[junit4] 2> 394431 T1352 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1382681350964/]
[junit4] 2> 394432 T1352 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 394432 T1352 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 394433 T1352 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 394433 T1352 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 394433 T1352 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 394434 T1352 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 394434 T1352 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 394434 T1352 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 394435 T1352 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 394436 T1352 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 394437 T1352 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 394437 T1352 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:48185/solr
[junit4] 2> 394437 T1352 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 394438 T1352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 394443 T1392 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2f18e82f name:ZooKeeperConnection Watcher:127.0.0.1:48185 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 394444 T1352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 394448 T1352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 394449 T1394 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@141203ab name:ZooKeeperConnection Watcher:127.0.0.1:48185/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 394450 T1352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 394456 T1352 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 395462 T1352 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45413_
[junit4] 2> 395464 T1352 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:45413_
[junit4] 2> 395472 T1394 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 395472 T1381 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 395472 T1374 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4] 2> 395480 T1395 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 395480 T1395 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 395482 T1395 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 395733 T1375 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 395735 T1375 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:48062",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:48062_",
[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> 395742 T1375 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:45413",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:45413_",
[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":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 395743 T1375 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 395744 T1375 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 395755 T1394 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> 395755 T1381 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> 395756 T1374 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> 396482 T1395 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 396483 T1395 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1382681350964/collection1
[junit4] 2> 396483 T1395 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 396485 T1395 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 396485 T1395 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 396487 T1395 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1382681350964/collection1/'
[junit4] 2> 396488 T1395 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1382681350964/collection1/lib/classes/' to classloader
[junit4] 2> 396488 T1395 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1382681350964/collection1/lib/README' to classloader
[junit4] 2> 396543 T1395 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 396601 T1395 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 396604 T1395 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 396611 T1395 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 397152 T1395 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 397153 T1395 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 397153 T1395 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 397159 T1395 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 397162 T1395 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 397183 T1395 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 397187 T1395 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 397191 T1395 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 397193 T1395 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 397194 T1395 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 397194 T1395 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 397196 T1395 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 397196 T1395 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 397197 T1395 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 397197 T1395 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1382681350964/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty1/
[junit4] 2> 397197 T1395 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7a29450
[junit4] 2> 397198 T1395 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty1
[junit4] 2> 397198 T1395 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty1/index/
[junit4] 2> 397199 T1395 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 397199 T1395 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty1/index
[junit4] 2> 397199 T1395 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=73.33984375, floorSegmentMB=1.697265625, forceMergeDeletesPctAllowed=6.977258620560708, segmentsPerTier=39.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4710161330546846
[junit4] 2> 397202 T1395 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 397203 T1395 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 397206 T1395 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 397207 T1395 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 397207 T1395 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 397207 T1395 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 397208 T1395 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 397208 T1395 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 397209 T1395 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 397209 T1395 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 397209 T1395 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 397210 T1395 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 397210 T1395 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 397211 T1395 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 397211 T1395 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 397212 T1395 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 397212 T1395 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 397214 T1395 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 397220 T1395 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 397221 T1395 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 397221 T1395 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=27, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 397223 T1395 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 397223 T1395 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 397223 T1395 oass.SolrIndexSearcher.<init> Opening Searcher@7499c8b4 main
[junit4] 2> 397239 T1396 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7499c8b4 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 397242 T1395 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 397242 T1395 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:45413 collection:collection1 shard:shard1
[junit4] 2> 397243 T1395 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 397256 T1395 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 397261 T1395 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 397261 T1395 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 397261 T1395 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:45413/collection1/
[junit4] 2> 397262 T1395 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 397262 T1395 oasc.SyncStrategy.syncToMe http://127.0.0.1:45413/collection1/ has no replicas
[junit4] 2> 397262 T1395 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:45413/collection1/ shard1
[junit4] 2> 397263 T1395 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 397269 T1375 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 397285 T1381 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> 397286 T1394 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> 397285 T1374 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> 397328 T1395 oasc.ZkController.register We are http://127.0.0.1:45413/collection1/ and leader is http://127.0.0.1:45413/collection1/
[junit4] 2> 397329 T1395 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:45413
[junit4] 2> 397329 T1395 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 397329 T1395 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 397329 T1395 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 397332 T1395 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 397334 T1352 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 397334 T1352 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 397406 T1352 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 397408 T1352 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54262
[junit4] 2> 397410 T1352 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 397410 T1352 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 397410 T1352 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1382681354001
[junit4] 2> 397411 T1352 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1382681354001/'
[junit4] 2> 397423 T1352 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1382681354001/solr.xml
[junit4] 2> 397480 T1352 oasc.CoreContainer.<init> New CoreContainer 2088240309
[junit4] 2> 397481 T1352 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1382681354001/]
[junit4] 2> 397482 T1352 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 397483 T1352 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 397483 T1352 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 397483 T1352 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 397484 T1352 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 397484 T1352 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 397485 T1352 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 397485 T1352 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 397485 T1352 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 397487 T1352 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 397487 T1352 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 397488 T1352 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:48185/solr
[junit4] 2> 397488 T1352 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 397489 T1352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 397491 T1408 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2b7d46ea name:ZooKeeperConnection Watcher:127.0.0.1:48185 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 397492 T1352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 397499 T1352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 397501 T1410 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1126321f name:ZooKeeperConnection Watcher:127.0.0.1:48185/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 397501 T1352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 397508 T1352 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 398514 T1352 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54262_
[junit4] 2> 398516 T1352 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54262_
[junit4] 2> 398522 T1374 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 398522 T1410 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 398523 T1381 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 398523 T1394 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4] 2> 398537 T1411 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 398538 T1411 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 398540 T1411 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 398798 T1375 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 398799 T1375 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:45413",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:45413_",
[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":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 398805 T1375 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:54262",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:54262_",
[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":"3",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 398805 T1375 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 398806 T1375 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 398813 T1410 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> 398813 T1374 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> 398813 T1381 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> 398813 T1394 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> 399541 T1411 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 399541 T1411 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1382681354001/collection1
[junit4] 2> 399542 T1411 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 399543 T1411 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 399543 T1411 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 399545 T1411 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1382681354001/collection1/'
[junit4] 2> 399546 T1411 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1382681354001/collection1/lib/classes/' to classloader
[junit4] 2> 399547 T1411 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1382681354001/collection1/lib/README' to classloader
[junit4] 2> 399595 T1411 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 399645 T1411 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 399647 T1411 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 399654 T1411 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 400166 T1411 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 400167 T1411 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 400168 T1411 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 400173 T1411 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 400176 T1411 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 400199 T1411 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 400203 T1411 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 400208 T1411 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 400210 T1411 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 400210 T1411 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 400211 T1411 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 400212 T1411 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 400213 T1411 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 400213 T1411 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 400213 T1411 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1382681354001/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty2/
[junit4] 2> 400214 T1411 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7a29450
[junit4] 2> 400214 T1411 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty2
[junit4] 2> 400215 T1411 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty2/index/
[junit4] 2> 400215 T1411 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 400215 T1411 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty2/index
[junit4] 2> 400216 T1411 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=73.33984375, floorSegmentMB=1.697265625, forceMergeDeletesPctAllowed=6.977258620560708, segmentsPerTier=39.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4710161330546846
[junit4] 2> 400225 T1411 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 400226 T1411 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 400230 T1411 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 400231 T1411 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 400231 T1411 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 400231 T1411 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 400232 T1411 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 400232 T1411 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 400232 T1411 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 400233 T1411 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 400233 T1411 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 400240 T1411 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 400241 T1411 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 400242 T1411 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 400242 T1411 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 400243 T1411 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 400244 T1411 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 400246 T1411 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 400250 T1411 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 400250 T1411 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 400251 T1411 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=27, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 400253 T1411 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 400254 T1411 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 400254 T1411 oass.SolrIndexSearcher.<init> Opening Searcher@3e3d5b00 main
[junit4] 2> 400259 T1412 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3e3d5b00 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 400261 T1411 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 400261 T1411 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54262 collection:collection1 shard:shard2
[junit4] 2> 400263 T1411 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 400278 T1411 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 400283 T1411 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 400283 T1411 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 400284 T1411 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54262/collection1/
[junit4] 2> 400284 T1411 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 400285 T1411 oasc.SyncStrategy.syncToMe http://127.0.0.1:54262/collection1/ has no replicas
[junit4] 2> 400285 T1411 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54262/collection1/ shard2
[junit4] 2> 400286 T1411 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 400325 T1375 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 400337 T1410 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> 400337 T1374 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> 400337 T1381 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> 400337 T1394 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> 400349 T1411 oasc.ZkController.register We are http://127.0.0.1:54262/collection1/ and leader is http://127.0.0.1:54262/collection1/
[junit4] 2> 400349 T1411 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54262
[junit4] 2> 400350 T1411 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 400350 T1411 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 400350 T1411 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 400352 T1411 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 400354 T1352 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 400354 T1352 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 400426 T1352 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 400428 T1352 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49863
[junit4] 2> 400430 T1352 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 400430 T1352 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 400431 T1352 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1382681357020
[junit4] 2> 400431 T1352 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1382681357020/'
[junit4] 2> 400458 T1352 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1382681357020/solr.xml
[junit4] 2> 400500 T1352 oasc.CoreContainer.<init> New CoreContainer 1216307886
[junit4] 2> 400501 T1352 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1382681357020/]
[junit4] 2> 400502 T1352 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4] 2> 400502 T1352 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4] 2> 400503 T1352 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 400503 T1352 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 400503 T1352 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 400504 T1352 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 400504 T1352 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 400505 T1352 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 400505 T1352 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 400506 T1352 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 400507 T1352 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 400507 T1352 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:48185/solr
[junit4] 2> 400508 T1352 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 400509 T1352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 400511 T1424 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2327b2b1 name:ZooKeeperConnection Watcher:127.0.0.1:48185 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 400511 T1352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 400515 T1352 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 400516 T1426 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@26cc4eba name:ZooKeeperConnection Watcher:127.0.0.1:48185/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 400517 T1352 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 400533 T1352 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 401538 T1352 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49863_
[junit4] 2> 401542 T1352 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49863_
[junit4] 2> 401551 T1410 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 401552 T1394 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 401552 T1374 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 401553 T1381 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 401554 T1426 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4] 2> 401565 T1427 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 401565 T1427 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 401567 T1427 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 401854 T1375 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 401855 T1375 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"active",
[junit4] 2> "base_url":"http://127.0.0.1:54262",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:54262_",
[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":"3",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 401862 T1375 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:49863",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:49863_",
[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":"3",
[junit4] 2> "core_node_name":"core_node3"}
[junit4] 2> 401862 T1375 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 401862 T1375 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4] 2> 401868 T1410 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> 401868 T1381 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> 401869 T1426 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> 401869 T1374 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> 401868 T1394 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> 402568 T1427 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 402568 T1427 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1382681357020/collection1
[junit4] 2> 402569 T1427 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 402570 T1427 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 402571 T1427 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 402573 T1427 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1382681357020/collection1/'
[junit4] 2> 402574 T1427 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1382681357020/collection1/lib/classes/' to classloader
[junit4] 2> 402574 T1427 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1382681357020/collection1/lib/README' to classloader
[junit4] 2> 402634 T1427 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_46
[junit4] 2> 402687 T1427 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 402689 T1427 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 402699 T1427 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 403321 T1427 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 403322 T1427 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4] 2> 403323 T1427 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 403334 T1427 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 403337 T1427 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 403358 T1427 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 403371 T1427 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 403376 T1427 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 403378 T1427 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 403378 T1427 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 403379 T1427 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 403382 T1427 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4] 2> 403383 T1427 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4] 2> 403383 T1427 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 403383 T1427 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1382681357020/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty3/
[junit4] 2> 403384 T1427 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7a29450
[junit4] 2> 403385 T1427 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty3
[junit4] 2> 403385 T1427 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty3/index/
[junit4] 2> 403385 T1427 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty3/index' doesn't exist. Creating new index...
[junit4] 2> 403386 T1427 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty3/index
[junit4] 2> 403386 T1427 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=49, maxMergeAtOnceExplicit=43, maxMergedSegmentMB=73.33984375, floorSegmentMB=1.697265625, forceMergeDeletesPctAllowed=6.977258620560708, segmentsPerTier=39.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4710161330546846
[junit4] 2> 403389 T1427 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty3/index,segFN=segments_1,generation=1}
[junit4] 2> 403390 T1427 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 403396 T1427 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 403396 T1427 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 403397 T1427 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 403397 T1427 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 403398 T1427 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 403398 T1427 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 403399 T1427 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 403399 T1427 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 403400 T1427 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 403401 T1427 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 403402 T1427 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 403402 T1427 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 403402 T1427 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 403403 T1427 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 403404 T1427 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 403407 T1427 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 403410 T1427 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 403411 T1427 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 403412 T1427 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=27, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 403413 T1427 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty3/index,segFN=segments_1,generation=1}
[junit4] 2> 403414 T1427 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 403414 T1427 oass.SolrIndexSearcher.<init> Opening Searcher@4f49ba55 main
[junit4] 2> 403421 T1428 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4f49ba55 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 403424 T1427 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 403424 T1427 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49863 collection:collection1 shard:shard3
[junit4] 2> 403426 T1427 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4] 2> 403436 T1427 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard3
[junit4] 2> 403440 T1427 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 403440 T1427 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 403440 T1427 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49863/collection1/
[junit4] 2> 403441 T1427 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 403441 T1427 oasc.SyncStrategy.syncToMe http://127.0.0.1:49863/collection1/ has no replicas
[junit4] 2> 403441 T1427 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49863/collection1/ shard3
[junit4] 2> 403442 T1427 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4] 2> 404887 T1375 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 404901 T1410 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> 404901 T1374 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> 404901 T1394 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> 404901 T1426 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> 404901 T1381 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> 404906 T1427 oasc.ZkController.register We are http://127.0.0.1:49863/collection1/ and leader is http://127.0.0.1:49863/collection1/
[junit4] 2> 404906 T1427 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49863
[junit4] 2> 404907 T1427 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 404907 T1427 oasc.ZkController.publish publishing core=collection1 state=active
[junit4] 2> 404907 T1427 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 404910 T1427 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 404912 T1352 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4] 2> 404912 T1352 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 404989 T1352 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 404992 T1352 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:41694
[junit4] 2> 404993 T1352 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 404993 T1352 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 404994 T1352 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1382681361578
[junit4] 2> 404994 T1352 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1382681361578/'
[junit4] 2> 405006 T1352 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-
[...truncated too long message...]
junit4] 2> 464618 T1352 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4] 2> 464620 T1707 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 464621 T1707 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:58403",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:58403_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "core_node_name":"core_node11"}
[junit4] 2> 464622 T1707 oasc.Overseer$ClusterStateUpdater.updateState shard=shard2 is already registered
[junit4] 2> 464627 T1707 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4] 2> "operation":"state",
[junit4] 2> "state":"down",
[junit4] 2> "base_url":"http://127.0.0.1:58403",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:58403_",
[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":null,
[junit4] 2> "core_node_name":"core_node11"}
[junit4] 2> 464671 T1352 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 56963
[junit4] 2> 464671 T1352 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=13439860
[junit4] 2> 464703 T1584 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> 464946 T1549 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 465706 T1352 oasc.ZkController.publish publishing core=collection1 state=down
[junit4] 2> 465707 T1352 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 465710 T1352 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@5e889555
[junit4] 2> 465814 T1352 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=10,autocommits=0,soft autocommit maxTime=1000ms,soft autocommits=8,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=74,cumulative_deletesById=34,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4] 2> 465815 T1352 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 465816 T1352 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 465816 T1352 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 465817 T1352 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 465823 T1352 oasc.CachingDirectoryFactory.close Closing StandardDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 465824 T1352 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty12/index.20131025010953441 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty12/index.20131025010953441;done=false>>]
[junit4] 2> 465824 T1352 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty12/index.20131025010953441
[junit4] 2> 465824 T1352 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty12 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty12;done=false>>]
[junit4] 2> 465825 T1352 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1382681347309/jetty12
[junit4] 2> 465827 T1707 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=90615404777504796-127.0.0.1:56963_-n_0000000012) am no longer a leader.
[junit4] 2> 465828 T1584 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 465851 T1352 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4] 2> 466096 T1566 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 466260 T1352 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4] 2> 466263 T1352 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:48185 48185
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 1> safe stop:
[junit4] 1> safe stop:
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeySafeLeaderTest -Dtests.method=testDistribSearch -Dtests.seed=EEAB6C82211B36F0 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=fr -Dtests.timezone=America/Cancun -Dtests.file.encoding=UTF-8
[junit4] FAILURE 75.9s J1 | ChaosMonkeySafeLeaderTest.testDistribSearch <<<
[junit4] > Throwable #1: java.lang.AssertionError: shard2 is not consistent. Got 43 from http://127.0.0.1:45941/collection1lastClient and got 41 from http://127.0.0.1:58403/collection1
[junit4] > at __randomizedtesting.SeedInfo.seed([EEAB6C82211B36F0:6F4DE29A564456CC]:0)
[junit4] > at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1148)
[junit4] > at org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.doTest(ChaosMonkeySafeLeaderTest.java:135)
[junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4] > at java.lang.Thread.run(Thread.java:662)
[junit4] 2> 466551 T1352 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: test params are: codec=Lucene45: {range_facet_l=Pulsing41(freqCutoff=16 minBlockSize=81 maxBlockSize=169), text=MockVariableIntBlock(baseBlockSize=82), _version_=PostingsFormat(name=Direct), rnd_b=PostingsFormat(name=Asserting), intDefault=PostingsFormat(name=Direct), id=PostingsFormat(name=Asserting), timestamp=Pulsing41(freqCutoff=16 minBlockSize=81 maxBlockSize=169), a_t=Pulsing41(freqCutoff=16 minBlockSize=81 maxBlockSize=169), range_facet_sl=PostingsFormat(name=Asserting), range_facet_si=Pulsing41(freqCutoff=16 minBlockSize=81 maxBlockSize=169), other_tl1=PostingsFormat(name=Direct), multiDefault=Pulsing41(freqCutoff=16 minBlockSize=81 maxBlockSize=169), a_si=PostingsFormat(name=Direct)}, docValues:{}, sim=DefaultSimilarity, locale=fr, timezone=America/Cancun
[junit4] 2> NOTE: Linux 3.8.0-32-generic amd64/Sun Microsystems Inc. 1.6.0_45 (64-bit)/cpus=8,threads=3,free=141166144,total=376848384
[junit4] 2> NOTE: All tests run in this JVM: [TestFieldCollectionResource, MultiTermTest, TestCloudManagedSchema, LeaderElectionIntegrationTest, TimeZoneUtilsTest, CoreContainerCoreInitFailuresTest, BadIndexSchemaTest, HighlighterTest, TestUtils, BlockDirectoryTest, AddBlockUpdateTest, TestLazyCores, TestMultiCoreConfBootstrap, BasicDistributedZk2Test, DefaultValueUpdateProcessorTest, IndexBasedSpellCheckerTest, SolrCmdDistributorTest, TestQuerySenderListener, HighlighterConfigTest, OutputWriterTest, CustomCollectionTest, TestCSVResponseWriter, TestCoreDiscovery, ConvertedLegacyTest, ZkSolrClientTest, TestRTGBase, MinimalSchemaTest, TestWordDelimiterFilterFactory, TestFieldTypeCollectionResource, TestSolrXmlPersistor, StandardRequestHandlerTest, PathHierarchyTokenizerFactoryTest, TestNRTOpen, TestFastOutputStream, OpenExchangeRatesOrgProviderTest, SignatureUpdateProcessorFactoryTest, TestInfoStreamLogging, SolrIndexConfigTest, TestSolrQueryParserResource, PreAnalyzedFieldTest, StressHdfsTest, TestRecovery, SimplePostToolTest, FieldAnalysisRequestHandlerTest, ChaosMonkeySafeLeaderTest]
[junit4] Completed on J1 in 75.95s, 1 test, 1 failure <<< FAILURES!
[...truncated 717 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:428: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:408: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:483: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1263: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:906: There were test failures: 328 suites, 1455 tests, 1 failure, 36 ignored (7 assumptions)
Total time: 47 minutes 38 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.6.0_45 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure