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 2014/05/04 01:25:07 UTC
[JENKINS] Lucene-Solr-trunk-Linux (64bit/jdk1.7.0_55) - Build #
10227 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/10227/
Java: 64bit/jdk1.7.0_55 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.testDistribSearch
Error Message:
shard3 is not consistent. Got 116 from http://127.0.0.1:44587/collection1lastClient and got 81 from http://127.0.0.1:46252/collection1
Stack Trace:
java.lang.AssertionError: shard3 is not consistent. Got 116 from http://127.0.0.1:44587/collection1lastClient and got 81 from http://127.0.0.1:46252/collection1
at __randomizedtesting.SeedInfo.seed([708B2846E97477D9:F16DA65E9E2B17E5]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1130)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1109)
at org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.doTest(ChaosMonkeySafeLeaderTest.java:150)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:865)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
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:65)
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:360)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
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 com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
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:65)
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:360)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 11045 lines...]
[junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
[junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/init-core-data-001
[junit4] 2> 281563 T1655 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (true)
[junit4] 2> 281564 T1655 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4] 2> 281567 T1655 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4] 2> 281568 T1655 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 281568 T1656 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4] 2> 281668 T1655 oasc.ZkTestServer.run start zk server on port:60869
[junit4] 2> 281669 T1655 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 282414 T1662 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@67b19f85 name:ZooKeeperConnection Watcher:127.0.0.1:60869 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 282414 T1655 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 282415 T1655 oascc.SolrZkClient.makePath makePath: /solr
[junit4] 2> 282421 T1655 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 282424 T1664 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@dd614eb name:ZooKeeperConnection Watcher:127.0.0.1:60869/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 282424 T1655 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 282424 T1655 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4] 2> 282427 T1655 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4] 2> 282429 T1655 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4] 2> 282431 T1655 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4] 2> 282432 T1655 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4] 2> 282433 T1655 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4] 2> 282435 T1655 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4] 2> 282436 T1655 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4] 2> 282438 T1655 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 282438 T1655 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
[junit4] 2> 282440 T1655 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4] 2> 282440 T1655 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4] 2> 282442 T1655 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4] 2> 282442 T1655 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4] 2> 282445 T1655 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4] 2> 282445 T1655 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4] 2> 282447 T1655 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
[junit4] 2> 282447 T1655 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
[junit4] 2> 282449 T1655 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4] 2> 282449 T1655 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4] 2> 282451 T1655 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 282451 T1655 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4] 2> 282453 T1655 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4] 2> 282453 T1655 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4] 2> 282455 T1655 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4] 2> 282456 T1655 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4] 2> 282706 T1655 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 282708 T1655 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:43703
[junit4] 2> 282709 T1655 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 282709 T1655 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 282709 T1655 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-002
[junit4] 2> 282710 T1655 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-002/'
[junit4] 2> 282722 T1655 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-002/solr.xml
[junit4] 2> 282770 T1655 oasc.CoreContainer.<init> New CoreContainer 1193735844
[junit4] 2> 282771 T1655 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-002/]
[junit4] 2> 282771 T1655 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 282772 T1655 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 282772 T1655 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 282772 T1655 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 282772 T1655 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 282773 T1655 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 282773 T1655 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 282773 T1655 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 282773 T1655 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 282774 T1655 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 282774 T1655 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 282774 T1655 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 282775 T1655 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60869/solr
[junit4] 2> 282775 T1655 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 282775 T1655 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 282778 T1675 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4f0aad7a name:ZooKeeperConnection Watcher:127.0.0.1:60869 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 282778 T1655 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 282780 T1655 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 282781 T1677 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@12f54b50 name:ZooKeeperConnection Watcher:127.0.0.1:60869/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 282781 T1655 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 282783 T1655 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4] 2> 282785 T1655 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4] 2> 282787 T1655 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
[junit4] 2> 282789 T1655 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
[junit4] 2> 282791 T1655 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
[junit4] 2> 282793 T1655 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4] 2> 282795 T1655 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43703_
[junit4] 2> 282795 T1655 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:43703_
[junit4] 2> 282797 T1655 oascc.SolrZkClient.makePath makePath: /overseer_elect
[junit4] 2> 282799 T1655 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4] 2> 282801 T1655 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:43703_
[junit4] 2> 282801 T1655 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4] 2> 282803 T1655 oasc.Overseer.start Overseer (id=91695237232263171-127.0.0.1:43703_-n_0000000000) starting
[junit4] 2> 282806 T1655 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4] 2> 282816 T1679 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4] 2> 282816 T1655 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4] 2> 282817 T1679 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:43703_
[junit4] 2> 282818 T1655 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4] 2> 282819 T1655 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 282821 T1678 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4] 2> 282824 T1680 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
[junit4] 2> 282825 T1680 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 282825 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 282826 T1680 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 282826 T1678 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 282827 T1678 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:43703",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:43703_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"1",
[junit4] 2> "core_node_name":null}
[junit4] 2> 282827 T1678 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
[junit4] 2> 282827 T1678 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 282829 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 282830 T1677 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> 283826 T1680 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 283826 T1680 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4] 2> 283827 T1680 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 283827 T1680 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 283828 T1680 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 283828 T1680 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-002/collection1/'
[junit4] 2> 283829 T1680 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-002/collection1/lib/.svn/' to classloader
[junit4] 2> 283830 T1680 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-002/collection1/lib/classes/' to classloader
[junit4] 2> 283830 T1680 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-002/collection1/lib/README' to classloader
[junit4] 2> 283888 T1680 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 283923 T1680 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 283924 T1680 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 283930 T1680 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 284289 T1680 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 284291 T1680 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 284292 T1680 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 284295 T1680 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 284312 T1680 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
[junit4] 2> 284312 T1680 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 284313 T1680 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-002/collection1/, dataDir=./solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/control/data/
[junit4] 2> 284313 T1680 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@20b7f9af
[junit4] 2> 284313 T1680 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/control/data
[junit4] 2> 284314 T1680 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/control/data/index/
[junit4] 2> 284314 T1680 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/control/data/index' doesn't exist. Creating new index...
[junit4] 2> 284314 T1680 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/control/data/index
[junit4] 2> 284315 T1680 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=29, maxMergeAtOnceExplicit=47, maxMergedSegmentMB=21.525390625, floorSegmentMB=0.8017578125, forceMergeDeletesPctAllowed=11.393529625154411, segmentsPerTier=11.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.42750600862422306
[junit4] 2> 284319 T1680 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 284319 T1680 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 284323 T1680 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 284323 T1680 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 284323 T1680 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 284323 T1680 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 284324 T1680 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 284324 T1680 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 284324 T1680 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 284324 T1680 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 284325 T1680 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 284325 T1680 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 284325 T1680 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 284325 T1680 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 284326 T1680 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 284326 T1680 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 284326 T1680 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 284327 T1680 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 284327 T1680 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 284329 T1680 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 284331 T1680 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 284332 T1680 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 284332 T1680 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=47, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3121993273409128]
[junit4] 2> 284334 T1680 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/control/data/index,segFN=segments_1,generation=1}
[junit4] 2> 284334 T1680 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 284335 T1680 oass.SolrIndexSearcher.<init> Opening Searcher@36c2977[collection1] main
[junit4] 2> 284335 T1680 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
[junit4] 2> 284336 T1680 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 284336 T1680 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 284337 T1680 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 284337 T1680 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 284337 T1680 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 284338 T1680 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 284338 T1680 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 284338 T1680 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 284338 T1680 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 284341 T1681 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@36c2977[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 284343 T1680 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 284344 T1684 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:43703 collection:control_collection shard:shard1
[junit4] 2> 284345 T1655 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 284345 T1655 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 284346 T1684 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4] 2> 284347 T1655 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 284348 T1686 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@53241a7f name:ZooKeeperConnection Watcher:127.0.0.1:60869/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 284348 T1655 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 284350 T1655 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 284352 T1655 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
[junit4] 2> 284361 T1684 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 284363 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 284363 T1684 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 284363 T1684 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> ASYNC NEW_CORE C590 name=collection1 org.apache.solr.core.SolrCore@60b1ac81 url=http://127.0.0.1:43703/collection1 node=127.0.0.1:43703_ C590_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:43703, core=collection1, node_name=127.0.0.1:43703_}
[junit4] 2> 284364 T1684 C590 P43703 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:43703/collection1/
[junit4] 2> 284364 T1678 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 284364 T1684 C590 P43703 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 284364 T1684 C590 P43703 oasc.SyncStrategy.syncToMe http://127.0.0.1:43703/collection1/ has no replicas
[junit4] 2> 284364 T1684 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:43703/collection1/ shard1
[junit4] 2> 284364 T1684 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4] 2> 284366 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 284367 T1677 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> 284367 T1686 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> 284373 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 284374 T1678 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 284377 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 284479 T1686 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> 284479 T1677 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> 284524 T1684 oasc.ZkController.register We are http://127.0.0.1:43703/collection1/ and leader is http://127.0.0.1:43703/collection1/
[junit4] 2> 284524 T1684 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:43703
[junit4] 2> 284524 T1684 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 284525 T1684 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
[junit4] 2> 284525 T1684 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 284526 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 284527 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 284527 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 284527 T1684 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 284528 T1678 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 284529 T1678 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:43703",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:43703_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"control_collection",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 284625 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 284669 T1655 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
[junit4] 2> 284671 T1655 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 284673 T1655 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54668
[junit4] 2> 284673 T1655 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 284673 T1655 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 284674 T1655 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-003
[junit4] 2> 284674 T1655 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-003/'
[junit4] 2> 284689 T1655 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-003/solr.xml
[junit4] 2> 284727 T1686 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> 284727 T1677 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> 284736 T1655 oasc.CoreContainer.<init> New CoreContainer 1724727104
[junit4] 2> 284736 T1655 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-003/]
[junit4] 2> 284737 T1655 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 284738 T1655 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 284738 T1655 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 284738 T1655 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 284738 T1655 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 284739 T1655 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 284739 T1655 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 284739 T1655 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 284739 T1655 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 284740 T1655 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 284740 T1655 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 284740 T1655 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 284741 T1655 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60869/solr
[junit4] 2> 284741 T1655 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 284741 T1655 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 284743 T1697 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2cf3b77a name:ZooKeeperConnection Watcher:127.0.0.1:60869 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 284743 T1655 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 284746 T1655 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 284747 T1699 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3e58460b name:ZooKeeperConnection Watcher:127.0.0.1:60869/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 284747 T1655 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 284752 T1655 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 285755 T1655 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:54668_
[junit4] 2> 285757 T1655 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:54668_
[junit4] 2> 285769 T1700 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 285769 T1700 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 285771 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 285771 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 285771 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 285771 T1700 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 285772 T1678 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 285772 T1678 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:54668",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:54668_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 285772 T1678 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
[junit4] 2> 285773 T1678 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4] 2> 285775 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 285877 T1686 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> 285877 T1677 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> 285878 T1699 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> 286772 T1700 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 286772 T1700 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 286775 T1700 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 286776 T1700 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 286777 T1700 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 286777 T1700 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-003/collection1/'
[junit4] 2> 286778 T1700 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-003/collection1/lib/.svn/' to classloader
[junit4] 2> 286778 T1700 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-003/collection1/lib/classes/' to classloader
[junit4] 2> 286779 T1700 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-003/collection1/lib/README' to classloader
[junit4] 2> 286852 T1700 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 286898 T1700 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 286899 T1700 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 286909 T1700 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 287352 T1700 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 287354 T1700 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 287356 T1700 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 287359 T1700 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 287406 T1700 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 287407 T1700 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 287407 T1700 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-003/collection1/, dataDir=./solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/jetty1/
[junit4] 2> 287407 T1700 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@20b7f9af
[junit4] 2> 287408 T1700 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/jetty1
[junit4] 2> 287409 T1700 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/jetty1/index/
[junit4] 2> 287409 T1700 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/jetty1/index' doesn't exist. Creating new index...
[junit4] 2> 287410 T1700 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/jetty1/index
[junit4] 2> 287418 T1700 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=29, maxMergeAtOnceExplicit=47, maxMergedSegmentMB=21.525390625, floorSegmentMB=0.8017578125, forceMergeDeletesPctAllowed=11.393529625154411, segmentsPerTier=11.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.42750600862422306
[junit4] 2> 287460 T1700 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 287460 T1700 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 287466 T1700 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 287467 T1700 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 287467 T1700 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 287467 T1700 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 287468 T1700 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 287469 T1700 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 287473 T1700 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 287476 T1700 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 287476 T1700 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 287477 T1700 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 287478 T1700 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 287478 T1700 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 287478 T1700 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 287479 T1700 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 287479 T1700 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 287480 T1700 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 287481 T1700 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 287484 T1700 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 287487 T1700 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 287487 T1700 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 287488 T1700 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=47, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3121993273409128]
[junit4] 2> 287490 T1700 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/jetty1/index,segFN=segments_1,generation=1}
[junit4] 2> 287490 T1700 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 287491 T1700 oass.SolrIndexSearcher.<init> Opening Searcher@1ada0f1b[collection1] main
[junit4] 2> 287491 T1700 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 287492 T1700 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 287492 T1700 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 287493 T1700 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 287493 T1700 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 287493 T1700 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 287494 T1700 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 287494 T1700 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 287494 T1700 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 287494 T1700 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 287497 T1701 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1ada0f1b[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 287499 T1700 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 287503 T1704 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:54668 collection:collection1 shard:shard2
[junit4] 2> 287503 T1655 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 287503 T1655 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 287504 T1704 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4] 2> 287518 T1704 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
[junit4] 2> 287522 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 287522 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 287522 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 287524 T1678 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 287526 T1704 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 287527 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 287527 T1704 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 287528 T1677 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> 287528 T1686 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> 287528 T1699 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> ASYNC NEW_CORE C591 name=collection1 org.apache.solr.core.SolrCore@2eb13120 url=http://127.0.0.1:54668/collection1 node=127.0.0.1:54668_ C591_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:54668, core=collection1, node_name=127.0.0.1:54668_}
[junit4] 2> 287529 T1704 C591 P54668 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:54668/collection1/
[junit4] 2> 287531 T1704 C591 P54668 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 287531 T1704 C591 P54668 oasc.SyncStrategy.syncToMe http://127.0.0.1:54668/collection1/ has no replicas
[junit4] 2> 287531 T1704 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:54668/collection1/ shard2
[junit4] 2> 287531 T1704 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4] 2> 287554 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 287557 T1678 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 287560 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 287667 T1677 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> 287667 T1686 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> 287669 T1699 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> 287705 T1704 oasc.ZkController.register We are http://127.0.0.1:54668/collection1/ and leader is http://127.0.0.1:54668/collection1/
[junit4] 2> 287705 T1704 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:54668
[junit4] 2> 287705 T1704 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 287705 T1704 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 287705 T1704 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 287708 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 287708 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 287708 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 287709 T1678 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 287710 T1678 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:54668",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:54668_",
[junit4] 2> "shard":"shard2",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node1"}
[junit4] 2> 287712 T1704 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 287714 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 287816 T1699 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> 287816 T1686 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> 287817 T1677 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> 287926 T1655 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
[junit4] 2> 287927 T1655 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 287932 T1655 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57490
[junit4] 2> 287932 T1655 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 287933 T1655 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 287933 T1655 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-004
[junit4] 2> 287933 T1655 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-004/'
[junit4] 2> 287964 T1655 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-004/solr.xml
[junit4] 2> 288011 T1655 oasc.CoreContainer.<init> New CoreContainer 295706559
[junit4] 2> 288011 T1655 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-004/]
[junit4] 2> 288013 T1655 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 288013 T1655 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 288013 T1655 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 288014 T1655 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 288014 T1655 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 288014 T1655 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 288015 T1655 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 288015 T1655 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 288015 T1655 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 288016 T1655 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 288016 T1655 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 288017 T1655 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 288017 T1655 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60869/solr
[junit4] 2> 288018 T1655 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 288020 T1655 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 288021 T1715 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@27843da3 name:ZooKeeperConnection Watcher:127.0.0.1:60869 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 288021 T1655 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 288034 T1655 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 288036 T1717 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7d7dfbb6 name:ZooKeeperConnection Watcher:127.0.0.1:60869/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 288036 T1655 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 288044 T1655 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 289046 T1655 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57490_
[junit4] 2> 289048 T1655 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57490_
[junit4] 2> 289067 T1718 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 289067 T1718 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 289069 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 289069 T1718 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 289069 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 289070 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 289073 T1678 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 289074 T1678 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:57490",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:57490_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 289075 T1678 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 289075 T1678 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4] 2> 289078 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 289184 T1677 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> 289188 T1717 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> 289188 T1699 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> 289188 T1686 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> 290070 T1718 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
[junit4] 2> 290070 T1718 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4] 2> 290071 T1718 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4] 2> 290071 T1718 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 290072 T1718 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 290072 T1718 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-004/collection1/'
[junit4] 2> 290073 T1718 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-004/collection1/lib/.svn/' to classloader
[junit4] 2> 290073 T1718 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-004/collection1/lib/classes/' to classloader
[junit4] 2> 290074 T1718 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-004/collection1/lib/README' to classloader
[junit4] 2> 290142 T1718 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
[junit4] 2> 290195 T1718 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4] 2> 290197 T1718 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4] 2> 290205 T1718 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4] 2> 290598 T1718 oass.IndexSchema.readSchema default search field in schema is text
[junit4] 2> 290601 T1718 oass.IndexSchema.readSchema unique key field: id
[junit4] 2> 290602 T1718 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 290608 T1718 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4] 2> 290634 T1718 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
[junit4] 2> 290635 T1718 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4] 2> 290635 T1718 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-004/collection1/, dataDir=./solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/jetty2/
[junit4] 2> 290635 T1718 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@20b7f9af
[junit4] 2> 290636 T1718 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/jetty2
[junit4] 2> 290636 T1718 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/jetty2/index/
[junit4] 2> 290636 T1718 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/jetty2/index' doesn't exist. Creating new index...
[junit4] 2> 290636 T1718 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/jetty2/index
[junit4] 2> 290637 T1718 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=29, maxMergeAtOnceExplicit=47, maxMergedSegmentMB=21.525390625, floorSegmentMB=0.8017578125, forceMergeDeletesPctAllowed=11.393529625154411, segmentsPerTier=11.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.42750600862422306
[junit4] 2> 290641 T1718 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 290641 T1718 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 290646 T1718 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
[junit4] 2> 290646 T1718 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
[junit4] 2> 290646 T1718 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 290647 T1718 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 290647 T1718 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 290647 T1718 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 290647 T1718 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 290648 T1718 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 290648 T1718 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 290648 T1718 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4] 2> 290649 T1718 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4] 2> 290649 T1718 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4] 2> 290650 T1718 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4] 2> 290652 T1718 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4] 2> 290653 T1718 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4] 2> 290653 T1718 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
[junit4] 2> 290654 T1718 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
[junit4] 2> 290661 T1718 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4] 2> 290663 T1718 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 290664 T1718 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 290665 T1718 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=47, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.3121993273409128]
[junit4] 2> 290666 T1718 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/jetty2/index,segFN=segments_1,generation=1}
[junit4] 2> 290667 T1718 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4] 2> 290667 T1718 oass.SolrIndexSearcher.<init> Opening Searcher@5841c8fe[collection1] main
[junit4] 2> 290667 T1718 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
[junit4] 2> 290669 T1718 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
[junit4] 2> 290669 T1718 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
[junit4] 2> 290669 T1718 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
[junit4] 2> 290670 T1718 oasr.RestManager.init Initializing RestManager with initArgs: {}
[junit4] 2> 290670 T1718 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 290671 T1718 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
[junit4] 2> 290671 T1718 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
[junit4] 2> 290671 T1718 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
[junit4] 2> 290671 T1718 oasr.RestManager.init Initializing 0 registered ManagedResources
[junit4] 2> 290675 T1719 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5841c8fe[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4] 2> 290677 T1718 oasc.CoreContainer.registerCore registering core: collection1
[junit4] 2> 290681 T1722 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57490 collection:collection1 shard:shard1
[junit4] 2> 290681 T1655 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
[junit4] 2> 290682 T1655 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4] 2> 290686 T1722 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4] 2> 290698 T1722 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
[junit4] 2> 290700 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 290701 T1722 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4] 2> 290701 T1722 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4] 2> 290701 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> ASYNC NEW_CORE C592 name=collection1 org.apache.solr.core.SolrCore@5e7defa6 url=http://127.0.0.1:57490/collection1 node=127.0.0.1:57490_ C592_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:57490, core=collection1, node_name=127.0.0.1:57490_}
[junit4] 2> 290701 T1722 C592 P57490 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57490/collection1/
[junit4] 2> 290701 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 290702 T1722 C592 P57490 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4] 2> 290702 T1722 C592 P57490 oasc.SyncStrategy.syncToMe http://127.0.0.1:57490/collection1/ has no replicas
[junit4] 2> 290703 T1722 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57490/collection1/ shard1
[junit4] 2> 290703 T1678 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 290703 T1722 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4] 2> 290707 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 290708 T1677 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> 290708 T1686 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> 290708 T1699 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> 290708 T1717 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> 290723 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 290724 T1678 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 290726 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 290828 T1686 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> 290828 T1699 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> 290828 T1677 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> 290828 T1717 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> 290874 T1722 oasc.ZkController.register We are http://127.0.0.1:57490/collection1/ and leader is http://127.0.0.1:57490/collection1/
[junit4] 2> 290874 T1722 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57490
[junit4] 2> 290874 T1722 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4] 2> 290875 T1722 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
[junit4] 2> 290875 T1722 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 290878 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 290878 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 290878 T1722 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 290879 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 290879 T1678 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 290880 T1678 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:57490",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:57490_",
[junit4] 2> "shard":"shard1",
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":"core_node2"}
[junit4] 2> 290882 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 290988 T1686 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> 290988 T1677 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> 290988 T1699 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> 290988 T1717 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> 291022 T1655 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
[junit4] 2> 291023 T1655 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4] 2> 291026 T1655 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:41736
[junit4] 2> 291027 T1655 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4] 2> 291027 T1655 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 291028 T1655 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-005
[junit4] 2> 291028 T1655 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-005/'
[junit4] 2> 291045 T1655 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-005/solr.xml
[junit4] 2> 291088 T1655 oasc.CoreContainer.<init> New CoreContainer 931301926
[junit4] 2> 291088 T1655 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-005/]
[junit4] 2> 291089 T1655 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
[junit4] 2> 291089 T1655 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to:
[junit4] 2> 291090 T1655 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4] 2> 291090 T1655 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4] 2> 291090 T1655 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4] 2> 291090 T1655 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4] 2> 291091 T1655 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4] 2> 291091 T1655 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4] 2> 291091 T1655 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4] 2> 291091 T1655 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 291092 T1655 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 291092 T1655 oasc.CoreContainer.load Host Name: 127.0.0.1
[junit4] 2> 291092 T1655 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:60869/solr
[junit4] 2> 291093 T1655 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4] 2> 291094 T1655 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 291096 T1733 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5b3be142 name:ZooKeeperConnection Watcher:127.0.0.1:60869 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 291096 T1655 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 291099 T1655 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4] 2> 291101 T1735 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1aa6a2fc name:ZooKeeperConnection Watcher:127.0.0.1:60869/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 291101 T1655 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4] 2> 291116 T1655 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4] 2> 292126 T1655 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41736_
[junit4] 2> 292128 T1655 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:41736_
[junit4] 2> 292141 T1736 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
[junit4] 2> 292141 T1736 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4] 2> 292143 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 292143 T1736 oasc.ZkController.waitForCoreNodeName look for our core node name
[junit4] 2> 292143 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 292144 T1677 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
[junit4] 2> 292146 T1678 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4] 2> 292147 T1678 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:41736",
[junit4] 2> "core":"collection1",
[junit4] 2> "roles":null,
[junit4] 2> "node_name":"127.0.0.1:41736_",
[junit4] 2> "shard":null,
[junit4] 2> "collection":"collection1",
[junit4] 2> "numShards":"3",
[junit4] 2> "core_node_name":null}
[junit4] 2> 292147 T1678 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4] 2> 292147 T1678 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shar
[...truncated too long message...]
r closing IndexWriter with IndexWriterCloser
[junit4] 2> 397422 T1836 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 397427 T1836 oasc.CachingDirectoryFactory.close Closing StandardDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 397427 T1836 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/jetty8 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/jetty8;done=false>>]
[junit4] 2> 397427 T1836 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/jetty8
[junit4] 2> 397427 T1836 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/jetty8/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/jetty8/index;done=false>>]
[junit4] 2> 397427 T1836 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/jetty8/index
[junit4] 2> 397427 T1836 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> 397428 T1836 oasc.LeaderElector$ElectionWatcher.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1472)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:260)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:257)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:94)
[junit4] 2> at org.apache.solr.cloud.LeaderElector.access$200(LeaderElector.java:55)
[junit4] 2> at org.apache.solr.cloud.LeaderElector$ElectionWatcher.process(LeaderElector.java:303)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:522)
[junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:498)
[junit4] 2>
[junit4] 2> ASYNC NEW_CORE C1814 name=collection1 org.apache.solr.core.SolrCore@f65826 url=http://127.0.0.1:55117/collection1 node=127.0.0.1:55117_ C1814_STATE=coll:collection1 core:collection1 props:{state=active, base_url=http://127.0.0.1:55117, core=collection1, node_name=127.0.0.1:55117_}
[junit4] 2> 397702 T2139 C1814 P55117 oasc.SyncStrategy.sync WARN Closed, skipping sync up.
[junit4] 2> 397704 T2139 oasc.ShardLeaderElectionContext.rejoinLeaderElection Not rejoining election because CoreContainer is shutdown
[junit4] 2> 397704 T2139 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@f65826
[junit4] 2> 397706 T2139 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=22,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=47,cumulative_deletesById=21,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=12888,transaction_logs_total_number=2}
[junit4] 2> 397707 T2139 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4] 2> 397707 T2139 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4] 2> 397707 T2139 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4] 2> 397742 T2139 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4] 2> 397747 T2139 oasc.CachingDirectoryFactory.close Closing StandardDirectoryFactory - 2 directories currently being tracked
[junit4] 2> 397747 T2139 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/jetty11/index.20140503190547429 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/jetty11/index.20140503190547429;done=false>>]
[junit4] 2> 397748 T2139 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/jetty11/index.20140503190547429
[junit4] 2> 397748 T2139 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/jetty11 [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/jetty11;done=false>>]
[junit4] 2> 397748 T2139 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001/tempDir-001/jetty11
[junit4] 2> 397748 T2139 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4] 2> NOTE: leaving temporary files on disk at: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-708B2846E97477D9-001
[junit4] 2> NOTE: test params are: codec=Lucene40, sim=DefaultSimilarity, locale=en_MT, timezone=America/Indianapolis
[junit4] 2> NOTE: Linux 3.8.0-38-generic amd64/Oracle Corporation 1.7.0_55 (64-bit)/cpus=8,threads=1,free=84755448,total=273154048
[junit4] 2> NOTE: All tests run in this JVM: [BadIndexSchemaTest, TestQueryTypes, TestSolrXMLSerializer, TestRangeQuery, SolrRequestParserTest, TestExceedMaxTermLength, DisMaxRequestHandlerTest, DistributedDebugComponentTest, TestDocumentBuilder, TestFieldCollectionResource, PluginInfoTest, NoFacetTest, TestXIncludeConfig, PrimUtilsTest, TestManagedSchemaFieldResource, TestRTGBase, TestDFRSimilarityFactory, RangeFacetTest, TestComponentsName, TestCSVResponseWriter, TestLazyCores, TestCSVLoader, TestSchemaSimilarityResource, SolrPluginUtilsTest, PathHierarchyTokenizerFactoryTest, TestSweetSpotSimilarityFactory, UniqFieldsUpdateProcessorFactoryTest, TestLRUCache, TestSolrQueryParserDefaultOperatorResource, MinimalSchemaTest, LegacyHTMLStripCharFilterTest, TestAnalyzedSuggestions, ResourceLoaderTest, RemoteQueryErrorTest, TestArbitraryIndexDir, DirectSolrConnectionTest, CoreContainerCoreInitFailuresTest, StatsComponentTest, SolrCoreCheckLockOnStartupTest, TestComplexPhraseQParserPlugin, OpenExchangeRatesOrgProviderTest, TestAtomicUpdateErrorCases, NoCacheHeaderTest, DeleteShardTest, TestMultiCoreConfBootstrap, IndexBasedSpellCheckerTest, TestPhraseSuggestions, AddSchemaFieldsUpdateProcessorFactoryTest, ShardRoutingCustomTest, TestOmitPositions, TestCollationField, AssignTest, AbstractAnalyticsStatsTest, SortByFunctionTest, HighlighterTest, SuggesterWFSTTest, TestCollectionAPI, DistributedQueryComponentOptimizationTest, TestFieldTypeCollectionResource, CustomCollectionTest, ExpressionTest, TestFreeTextSuggestions, HdfsRecoveryZkTest, HdfsDirectoryTest, SpellCheckCollatorTest, TestDistributedGrouping, TestManagedResourceStorage, TestRandomMergePolicy, ChaosMonkeySafeLeaderTest]
[junit4] Completed on J1 in 116.39s, 1 test, 1 failure <<< FAILURES!
[...truncated 826 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:447: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:496: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1296: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:920: There were test failures: 398 suites, 1670 tests, 1 failure, 37 ignored (16 assumptions)
Total time: 55 minutes 9 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_55 -XX:+UseCompressedOops -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure