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/03/26 17:53:08 UTC

[JENKINS] Lucene-Solr-4.7-Linux (32bit/ibm-j9-jdk7) - Build # 38 - Still Failing!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.7-Linux/38/
Java: 32bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}

3 tests failed.
FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.ChaosMonkeySafeLeaderTest

Error Message:
Suite timeout exceeded (>= 7200000 msec).

Stack Trace:
java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
	at __randomizedtesting.SeedInfo.seed([C6F54B120A1E6EE9]:0)


FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.ChaosMonkeySafeLeaderTest

Error Message:
Captured an uncaught exception in thread: Thread[id=3103, name=RecoveryThread, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]

Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=3103, name=RecoveryThread, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
Caused by: java.lang.AssertionError: file _1.cfs does not exist
	at __randomizedtesting.SeedInfo.seed([C6F54B120A1E6EE9]:0)
	at org.apache.lucene.index.IndexWriter.filesExist(IndexWriter.java:4390)
	at org.apache.lucene.index.IndexWriter.startCommit(IndexWriter.java:4456)
	at org.apache.lucene.index.IndexWriter.prepareCommitInternal(IndexWriter.java:2953)
	at org.apache.lucene.index.IndexWriter.commitInternal(IndexWriter.java:3049)
	at org.apache.lucene.index.IndexWriter.commit(IndexWriter.java:3016)
	at org.apache.solr.update.DirectUpdateHandler2.commit(DirectUpdateHandler2.java:578)
	at org.apache.solr.cloud.RecoveryStrategy.doRecovery(RecoveryStrategy.java:396)
	at org.apache.solr.cloud.RecoveryStrategy.run(RecoveryStrategy.java:247)


REGRESSION:  org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.testDistribSearch

Error Message:
Test abandoned because suite timeout was reached.

Stack Trace:
java.lang.Exception: Test abandoned because suite timeout was reached.
	at __randomizedtesting.SeedInfo.seed([C6F54B120A1E6EE9]:0)




Build Log:
[...truncated 11240 lines...]
   [junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
   [junit4]   2> 785800 T2683 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (true)
   [junit4]   2> 785800 T2683 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 785803 T2683 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/./solrtest-ChaosMonkeySafeLeaderTest-1395845537733
   [junit4]   2> 785804 T2683 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 785805 T2684 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 785905 T2683 oasc.ZkTestServer.run start zk server on port:38540
   [junit4]   2> 785907 T2683 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 786082 T2690 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4e183e0 name:ZooKeeperConnection Watcher:127.0.0.1:38540 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 786082 T2683 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 786082 T2683 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 786087 T2683 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 786088 T2692 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d3fc4361 name:ZooKeeperConnection Watcher:127.0.0.1:38540/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 786088 T2683 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 786088 T2683 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 786091 T2683 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 786093 T2683 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 786094 T2683 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 786096 T2683 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 786097 T2683 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 786100 T2683 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
   [junit4]   2> 786100 T2683 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 786103 T2683 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 786103 T2683 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 786106 T2683 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 786106 T2683 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 786109 T2683 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 786109 T2683 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 786111 T2683 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 786112 T2683 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 786115 T2683 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 786116 T2683 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 786122 T2683 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 786123 T2683 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 786127 T2683 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 786128 T2683 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 786132 T2683 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 786133 T2683 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 786137 T2683 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 786139 T2683 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 786211 T2683 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 786214 T2683 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:๕๙๗๘๙
   [junit4]   2> 786215 T2683 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 786215 T2683 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 786216 T2683 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1395845538074
   [junit4]   2> 786216 T2683 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1395845538074/'
   [junit4]   2> 786223 T2683 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1395845538074/solr.xml
   [junit4]   2> 786254 T2683 oasc.CoreContainer.<init> New CoreContainer 1378050257
   [junit4]   2> 786255 T2683 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1395845538074/]
   [junit4]   2> 786256 T2683 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 786257 T2683 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 786257 T2683 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 786258 T2683 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 786258 T2683 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 786259 T2683 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 786259 T2683 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 786260 T2683 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 786260 T2683 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 786261 T2683 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 786261 T2683 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 786262 T2683 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 786262 T2683 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:38540/solr
   [junit4]   2> 786263 T2683 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 786264 T2683 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 786265 T2703 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3ea963 name:ZooKeeperConnection Watcher:127.0.0.1:38540 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 786265 T2683 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 786267 T2683 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 786268 T2705 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f3cf6e4b name:ZooKeeperConnection Watcher:127.0.0.1:38540/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 786268 T2683 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 786269 T2683 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 786272 T2683 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 786274 T2683 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 786276 T2683 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59789_
   [junit4]   2> 786277 T2683 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:59789_
   [junit4]   2> 786280 T2683 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 786281 T2683 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 786284 T2683 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:59789_
   [junit4]   2> 786285 T2683 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 786287 T2683 oasc.Overseer.start Overseer (id=91478133161132035-127.0.0.1:59789_-n_0000000000) starting
   [junit4]   2> 786292 T2683 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 786296 T2707 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 786297 T2683 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 786297 T2707 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 786299 T2683 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 786301 T2683 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 786303 T2706 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 786306 T2708 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 786306 T2708 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 786308 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 786308 T2708 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 786309 T2706 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 786310 T2706 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:59789",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:59789_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 786310 T2706 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 786310 T2706 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 786312 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 786313 T2705 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> 787309 T2708 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 787309 T2708 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1395845538074/collection1
   [junit4]   2> 787310 T2708 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 787311 T2708 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 787311 T2708 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 787312 T2708 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 787312 T2708 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1395845538074/collection1/'
   [junit4]   2> 787313 T2708 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1395845538074/collection1/lib/classes/' to classloader
   [junit4]   2> 787314 T2708 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1395845538074/collection1/lib/README' to classloader
   [junit4]   2> 787365 T2708 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 787398 T2708 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 787400 T2708 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 787405 T2708 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 787696 T2708 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 787699 T2708 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 787701 T2708 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 787705 T2708 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 787721 T2708 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 787721 T2708 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1395845538074/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/control/data/
   [junit4]   2> 787721 T2708 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@9afd7b08
   [junit4]   2> 787722 T2708 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/control/data
   [junit4]   2> 787722 T2708 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/control/data/index/
   [junit4]   2> 787723 T2708 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 787723 T2708 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/control/data/index
   [junit4]   2> 787724 T2708 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=49, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.14311032420306866]
   [junit4]   2> 787742 T2708 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/control/data/index,segFN=segments_1,generation=1}
   [junit4]   2> 787743 T2708 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 787744 T2708 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 787745 T2708 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 787745 T2708 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 787745 T2708 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 787746 T2708 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 787746 T2708 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 787746 T2708 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 787747 T2708 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 787747 T2708 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 787747 T2708 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 787748 T2708 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 787748 T2708 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 787748 T2708 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 787749 T2708 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 787749 T2708 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 787749 T2708 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 787750 T2708 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 787753 T2708 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 787753 T2708 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 787754 T2708 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=4, maxMergeAtOnceExplicit=7, maxMergedSegmentMB=65.61328125, floorSegmentMB=1.5751953125, forceMergeDeletesPctAllowed=14.704427509356368, segmentsPerTier=24.0, maxCFSSegmentSizeMB=0.8818359375, noCFSRatio=0.0
   [junit4]   2> 787755 T2708 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/control/data/index,segFN=segments_1,generation=1}
   [junit4]   2> 787755 T2708 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 787755 T2708 oass.SolrIndexSearcher.<init> Opening Searcher@dba00e4a[collection1] main
   [junit4]   2> 787757 T2709 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@dba00e4a[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 787757 T2708 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 787758 T2683 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 787759 T2683 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 787758 T2712 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:59789 collection:control_collection shard:shard1
   [junit4]   2> 787761 T2683 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 787763 T2714 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9c0c2338 name:ZooKeeperConnection Watcher:127.0.0.1:38540/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 787763 T2712 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 787763 T2683 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 787764 T2683 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 787767 T2683 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 787768 T2712 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 787770 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 787770 T2712 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 787771 T2712 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C1555 name=collection1 org.apache.solr.core.SolrCore@a161e64a url=http://127.0.0.1:59789/collection1 node=127.0.0.1:59789_ C1555_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:59789, core=collection1, node_name=127.0.0.1:59789_}
   [junit4]   2> 787771 T2712 C1555 P59789 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:59789/collection1/
   [junit4]   2> 787771 T2706 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 787772 T2712 C1555 P59789 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 787773 T2712 C1555 P59789 oasc.SyncStrategy.syncToMe http://127.0.0.1:59789/collection1/ has no replicas
   [junit4]   2> 787773 T2712 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:59789/collection1/ shard1
   [junit4]   2> 787774 T2712 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 787775 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 787779 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 787782 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 787854 T2683 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 787855 T2683 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 787857 T2683 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:๓๕๔๑๖
   [junit4]   2> 787858 T2683 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 787858 T2683 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 787859 T2683 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1395845539696
   [junit4]   2> 787859 T2683 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1395845539696/'
   [junit4]   2> 787868 T2683 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1395845539696/solr.xml
   [junit4]   2> 787885 T2714 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> 787885 T2705 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> 787901 T2683 oasc.CoreContainer.<init> New CoreContainer 313066369
   [junit4]   2> 787902 T2683 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1395845539696/]
   [junit4]   2> 787903 T2683 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 787903 T2683 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 787904 T2683 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 787904 T2683 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 787905 T2683 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 787905 T2683 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 787906 T2683 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 787906 T2683 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 787907 T2683 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 787908 T2683 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 787908 T2683 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 787909 T2683 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 787909 T2683 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:38540/solr
   [junit4]   2> 787910 T2683 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 787911 T2683 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 787912 T2725 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1200ba51 name:ZooKeeperConnection Watcher:127.0.0.1:38540 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 787912 T2683 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 787914 T2683 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 787915 T2727 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f1083e43 name:ZooKeeperConnection Watcher:127.0.0.1:38540/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 787915 T2683 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 787918 T2683 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 787930 T2712 oasc.ZkController.register We are http://127.0.0.1:59789/collection1/ and leader is http://127.0.0.1:59789/collection1/
   [junit4]   2> 787930 T2712 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:59789
   [junit4]   2> 787930 T2712 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 787930 T2712 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 787931 T2712 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 787932 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 787932 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 787932 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 787932 T2712 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 787933 T2706 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 787934 T2706 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:59789",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:59789_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 787936 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 788038 T2705 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> 788038 T2714 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> 788039 T2727 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> 788921 T2683 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35416_
   [junit4]   2> 788922 T2683 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:35416_
   [junit4]   2> 788924 T2714 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 788925 T2727 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 788925 T2705 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 788930 T2728 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 788930 T2728 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 788935 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 788935 T2728 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 788935 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 788936 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 788936 T2706 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 788937 T2706 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:35416",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:35416_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 788937 T2706 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
   [junit4]   2> 788938 T2706 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 788941 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 789044 T2705 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> 789044 T2714 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> 789044 T2727 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> 789936 T2728 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 789936 T2728 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1395845539696/collection1
   [junit4]   2> 789936 T2728 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 789937 T2728 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 789937 T2728 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 789938 T2728 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 789938 T2728 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1395845539696/collection1/'
   [junit4]   2> 789939 T2728 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1395845539696/collection1/lib/classes/' to classloader
   [junit4]   2> 789939 T2728 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1395845539696/collection1/lib/README' to classloader
   [junit4]   2> 789979 T2728 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 790020 T2728 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 790021 T2728 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 790026 T2728 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 790330 T2728 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 790334 T2728 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 790337 T2728 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 790342 T2728 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 790362 T2728 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 790363 T2728 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1395845539696/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/jetty1/
   [junit4]   2> 790363 T2728 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@9afd7b08
   [junit4]   2> 790364 T2728 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/jetty1
   [junit4]   2> 790365 T2728 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/jetty1/index/
   [junit4]   2> 790365 T2728 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 790366 T2728 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/jetty1/index
   [junit4]   2> 790367 T2728 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=49, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.14311032420306866]
   [junit4]   2> 790369 T2728 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/jetty1/index,segFN=segments_1,generation=1}
   [junit4]   2> 790370 T2728 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 790372 T2728 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 790372 T2728 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 790373 T2728 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 790373 T2728 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 790373 T2728 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 790374 T2728 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 790374 T2728 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 790374 T2728 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 790375 T2728 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 790375 T2728 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 790375 T2728 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 790376 T2728 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 790376 T2728 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 790376 T2728 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 790377 T2728 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 790377 T2728 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 790378 T2728 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 790381 T2728 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 790381 T2728 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 790382 T2728 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=4, maxMergeAtOnceExplicit=7, maxMergedSegmentMB=65.61328125, floorSegmentMB=1.5751953125, forceMergeDeletesPctAllowed=14.704427509356368, segmentsPerTier=24.0, maxCFSSegmentSizeMB=0.8818359375, noCFSRatio=0.0
   [junit4]   2> 790383 T2728 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/jetty1/index,segFN=segments_1,generation=1}
   [junit4]   2> 790383 T2728 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 790383 T2728 oass.SolrIndexSearcher.<init> Opening Searcher@ea69d8d7[collection1] main
   [junit4]   2> 790386 T2729 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@ea69d8d7[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 790387 T2728 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 790388 T2683 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 790389 T2683 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 790388 T2732 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:35416 collection:collection1 shard:shard2
   [junit4]   2> 790393 T2732 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 790399 T2732 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 790400 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 790400 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 790400 T2732 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 790401 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 790401 T2732 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C1556 name=collection1 org.apache.solr.core.SolrCore@45b9b7af url=http://127.0.0.1:35416/collection1 node=127.0.0.1:35416_ C1556_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:35416, core=collection1, node_name=127.0.0.1:35416_}
   [junit4]   2> 790401 T2732 C1556 P35416 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:35416/collection1/
   [junit4]   2> 790402 T2732 C1556 P35416 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 790402 T2732 C1556 P35416 oasc.SyncStrategy.syncToMe http://127.0.0.1:35416/collection1/ has no replicas
   [junit4]   2> 790402 T2706 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 790402 T2732 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:35416/collection1/ shard2
   [junit4]   2> 790403 T2732 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 790405 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 790407 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 790411 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 790485 T2683 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 790485 T2683 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 790488 T2683 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:๕๑๖๒๐
   [junit4]   2> 790488 T2683 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 790489 T2683 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 790489 T2683 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1395845542319
   [junit4]   2> 790490 T2683 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1395845542319/'
   [junit4]   2> 790497 T2683 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1395845542319/solr.xml
   [junit4]   2> 790513 T2714 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> 790513 T2727 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> 790513 T2705 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> 790529 T2683 oasc.CoreContainer.<init> New CoreContainer 1196480550
   [junit4]   2> 790529 T2683 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1395845542319/]
   [junit4]   2> 790531 T2683 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 790531 T2683 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 790532 T2683 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 790532 T2683 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 790532 T2683 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 790533 T2683 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 790533 T2683 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 790534 T2683 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 790534 T2683 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 790535 T2683 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 790536 T2683 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 790536 T2683 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 790537 T2683 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:38540/solr
   [junit4]   2> 790537 T2683 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 790538 T2683 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 790540 T2743 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b5770bc1 name:ZooKeeperConnection Watcher:127.0.0.1:38540 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 790540 T2683 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 790542 T2683 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 790543 T2745 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@28cf6980 name:ZooKeeperConnection Watcher:127.0.0.1:38540/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 790543 T2683 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 790548 T2683 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 790558 T2732 oasc.ZkController.register We are http://127.0.0.1:35416/collection1/ and leader is http://127.0.0.1:35416/collection1/
   [junit4]   2> 790558 T2732 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:35416
   [junit4]   2> 790559 T2732 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 790559 T2732 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 790559 T2732 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 790560 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 790560 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 790560 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 790561 T2732 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 790561 T2706 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 790562 T2706 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:35416",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:35416_",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 790564 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 790666 T2705 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> 790666 T2714 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> 790666 T2727 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> 790666 T2745 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> 791550 T2683 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51620_
   [junit4]   2> 791552 T2683 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51620_
   [junit4]   2> 791554 T2745 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 791554 T2727 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 791554 T2714 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 791554 T2705 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 791559 T2746 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 791559 T2746 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 791560 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 791560 T2746 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 791560 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 791561 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 791562 T2706 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 791562 T2706 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:51620",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:51620_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 791562 T2706 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 791563 T2706 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 791564 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 791667 T2727 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> 791667 T2745 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> 791667 T2714 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> 791667 T2705 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> 792561 T2746 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 792564 T2746 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1395845542319/collection1
   [junit4]   2> 792565 T2746 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 792565 T2746 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 792566 T2746 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 792567 T2746 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 792567 T2746 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1395845542319/collection1/'
   [junit4]   2> 792568 T2746 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1395845542319/collection1/lib/classes/' to classloader
   [junit4]   2> 792568 T2746 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1395845542319/collection1/lib/README' to classloader
   [junit4]   2> 792604 T2746 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 792643 T2746 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 792644 T2746 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 792650 T2746 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 792948 T2746 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 792951 T2746 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 792953 T2746 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 792957 T2746 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 792977 T2746 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 792977 T2746 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1395845542319/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/jetty2/
   [junit4]   2> 792977 T2746 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@9afd7b08
   [junit4]   2> 792978 T2746 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/jetty2
   [junit4]   2> 792979 T2746 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/jetty2/index/
   [junit4]   2> 792979 T2746 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 792979 T2746 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/jetty2/index
   [junit4]   2> 792980 T2746 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=49, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.14311032420306866]
   [junit4]   2> 792982 T2746 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/jetty2/index,segFN=segments_1,generation=1}
   [junit4]   2> 792983 T2746 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 792985 T2746 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 792985 T2746 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 792986 T2746 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 792986 T2746 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 792986 T2746 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 792986 T2746 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 792987 T2746 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 792987 T2746 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 792987 T2746 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 792988 T2746 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 792988 T2746 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 792988 T2746 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 792989 T2746 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 792989 T2746 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 792989 T2746 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 792990 T2746 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 792991 T2746 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 792993 T2746 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 792994 T2746 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 792994 T2746 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=4, maxMergeAtOnceExplicit=7, maxMergedSegmentMB=65.61328125, floorSegmentMB=1.5751953125, forceMergeDeletesPctAllowed=14.704427509356368, segmentsPerTier=24.0, maxCFSSegmentSizeMB=0.8818359375, noCFSRatio=0.0
   [junit4]   2> 792995 T2746 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/jetty2/index,segFN=segments_1,generation=1}
   [junit4]   2> 792995 T2746 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 792996 T2746 oass.SolrIndexSearcher.<init> Opening Searcher@bcaad3d[collection1] main
   [junit4]   2> 792998 T2747 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@bcaad3d[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 793000 T2746 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 793001 T2683 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 793002 T2683 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 793001 T2750 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:51620 collection:collection1 shard:shard1
   [junit4]   2> 793007 T2750 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 793020 T2750 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 793023 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 793023 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 793024 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 793024 T2750 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 793025 T2750 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C1557 name=collection1 org.apache.solr.core.SolrCore@2a44fe51 url=http://127.0.0.1:51620/collection1 node=127.0.0.1:51620_ C1557_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:51620, core=collection1, node_name=127.0.0.1:51620_}
   [junit4]   2> 793025 T2750 C1557 P51620 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:51620/collection1/
   [junit4]   2> 793026 T2706 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 793026 T2750 C1557 P51620 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 793027 T2750 C1557 P51620 oasc.SyncStrategy.syncToMe http://127.0.0.1:51620/collection1/ has no replicas
   [junit4]   2> 793027 T2750 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:51620/collection1/ shard1
   [junit4]   2> 793028 T2750 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 793030 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 793035 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 793040 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 793074 T2683 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
   [junit4]   2> 793075 T2683 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 793077 T2683 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:๓๔๓๘๑
   [junit4]   2> 793078 T2683 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 793078 T2683 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 793079 T2683 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1395845544932
   [junit4]   2> 793079 T2683 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1395845544932/'
   [junit4]   2> 793087 T2683 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1395845544932/solr.xml
   [junit4]   2> 793119 T2683 oasc.CoreContainer.<init> New CoreContainer -800169611
   [junit4]   2> 793119 T2683 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1395845544932/]
   [junit4]   2> 793121 T2683 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 793121 T2683 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 793121 T2683 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 793122 T2683 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 793122 T2683 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 793123 T2683 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 793123 T2683 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 793124 T2683 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 793124 T2683 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 793125 T2683 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 793126 T2683 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 793126 T2683 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 793127 T2683 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:38540/solr
   [junit4]   2> 793127 T2683 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 793128 T2683 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 793130 T2761 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@396258ea name:ZooKeeperConnection Watcher:127.0.0.1:38540 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 793130 T2683 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 793132 T2683 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 793133 T2763 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@cdbdd253 name:ZooKeeperConnection Watcher:127.0.0.1:38540/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 793134 T2683 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 793137 T2683 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 793143 T2714 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> 793143 T2727 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> 793143 T2763 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> 793143 T2705 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> 793144 T2745 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> 793186 T2750 oasc.ZkController.register We are http://127.0.0.1:51620/collection1/ and leader is http://127.0.0.1:51620/collection1/
   [junit4]   2> 793187 T2750 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:51620
   [junit4]   2> 793187 T2750 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 793187 T2750 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 793187 T2750 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 793188 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 793189 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 793189 T2750 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 793189 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 793190 T2706 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 793190 T2706 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:51620",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:51620_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 793250 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 793353 T2705 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> 793353 T2745 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> 793353 T2727 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> 793353 T2714 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> 793353 T2763 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> 794140 T2683 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34381_
   [junit4]   2> 794142 T2683 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:34381_
   [junit4]   2> 794145 T2714 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 794145 T2705 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 794145 T2727 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 794145 T2745 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 794145 T2763 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 794153 T2764 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 794153 T2764 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 794154 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 794154 T2764 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 794155 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 794155 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 794156 T2706 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 794157 T2706 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:34381",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:34381_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 794157 T2706 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 794157 T2706 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 794159 T2705 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 794261 T2714 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 794261 T2727 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 794262 T2745 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 794262 T2705 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 794261 T2763 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 795155 T2764 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 795155 T2764 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1395845544932/collection1
   [junit4]   2> 795156 T2764 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 795156 T2764 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 795157 T2764 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 795157 T2764 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 795158 T2764 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1395845544932/collection1/'
   [junit4]   2> 795158 T2764 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1395845544932/collection1/lib/classes/' to classloader
   [junit4]   2> 795159 T2764 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1395845544932/collection1/lib/README' to classloader
   [junit4]   2> 795186 T2764 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_47
   [junit4]   2> 795229 T2764 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 795230 T2764 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 795235 T2764 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 795515 T2764 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 795517 T2764 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 795519 T2764 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 795523 T2764 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 795538 T2764 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 795538 T2764 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1395845544932/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/jetty3/
   [junit4]   2> 795539 T2764 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@9afd7b08
   [junit4]   2> 795539 T2764 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/jetty3
   [junit4]   2> 795540 T2764 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/jetty3/index/
   [junit4]   2> 795540 T2764 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 795540 T2764 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/jetty3/index
   [junit4]   2> 795541 T2764 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=49, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.14311032420306866]
   [junit4]   2> 795544 T2764 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1395845537733/jetty3/index,segFN=segments_1,generation=1}
   [junit4]   2> 795544 T2764 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 795546 T2764 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 795547 T2764 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 795547 T2764 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 795547 T2764 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 795547 T2764 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 795548 T2764 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 795548 T2764 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 795548 T2764 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 795549 T2764 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 795549 T2764 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 795549 T2764 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 795550 T2764 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 795550 T2764 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 795550 T2764 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 795551 T2764 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 795551 T2764 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 795552 T2764 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 795554 T2764 oasu.CommitTracker.<init> Hard AutoCommit: disabled
  

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

  [junit4]   2> 	        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2054)
   [junit4]   2> 	        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1090)
   [junit4]   2> 	        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:818)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1093)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1155)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:640)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:853)
   [junit4]   2> 	  95) Thread[id=3076, name=qtp-458435789-3076 Selector1, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at org.eclipse.jetty.io.nio.SelectorManager$1.run(SelectorManager.java:290)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:853)
   [junit4]   2> 	  96) Thread[id=2943, name=Thread-1393, state=WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at java.lang.Object.wait(Native Method)
   [junit4]   2> 	        at java.lang.Object.wait(Object.java:172)
   [junit4]   2> 	        at org.apache.solr.core.CloserThread.run(CoreContainer.java:1018)
   [junit4]   2> 	  97) Thread[id=2930, name=qtp-1514414976-2930 Acceptor0 SelectChannelConnector@127.0.0.1:๕๓๘๑๐, state=BLOCKED, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:956)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:853)
   [junit4]   2> 	  98) Thread[id=2942, name=searcherExecutor-1740-thread-1, state=WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at sun.misc.Unsafe.park(Native Method)
   [junit4]   2> 	        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:197)
   [junit4]   2> 	        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2054)
   [junit4]   2> 	        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:453)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1093)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1155)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:640)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:853)
   [junit4]   2> 	  99) Thread[id=2852, name=qtp371193876-2852 Acceptor1 SelectChannelConnector@127.0.0.1:๕๘๑๖๖, state=BLOCKED, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:956)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:853)
   [junit4]   2> 	  100) Thread[id=2783, name=searcherExecutor-1676-thread-1, state=WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at sun.misc.Unsafe.park(Native Method)
   [junit4]   2> 	        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:197)
   [junit4]   2> 	        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2054)
   [junit4]   2> 	        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:453)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1093)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1155)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:640)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:853)
   [junit4]   2> NOTE: test params are: codec=Lucene40, sim=DefaultSimilarity, locale=th_TH_TH_#u-nu-thai, timezone=America/Nome
   [junit4]   2> NOTE: Linux 3.8.0-37-generic x86/IBM Corporation 1.7.0 (32-bit)/cpus=8,threads=113,free=80262048,total=253231104
   [junit4]   2> NOTE: All tests run in this JVM: [TestFoldingMultitermQuery, TestBinaryResponseWriter, TestSolrXmlPersistor, TestComponentsName, TestSolrQueryParserResource, ShardRoutingCustomTest, TestNRTOpen, SuggestComponentTest, SimplePostToolTest, AlternateDirectoryTest, TestDefaultSimilarityFactory, TestQuerySenderNoQuery, PathHierarchyTokenizerFactoryTest, HdfsLockFactoryTest, FullSolrCloudDistribCmdsTest, AddBlockUpdateTest, TestClassNameShortening, CoreContainerCoreInitFailuresTest, SSLMigrationTest, TestCSVResponseWriter, DebugComponentTest, StatsComponentTest, TestSolrDeletionPolicy2, TestStressRecovery, TestAnalyzedSuggestions, DirectSolrSpellCheckerTest, OpenExchangeRatesOrgProviderTest, SuggesterTSTTest, TestDynamicFieldResource, OpenCloseCoreStressTest, TestSolrXmlPersistence, TestFieldCollectionResource, IndexSchemaRuntimeFieldTest, TestCollapseQParserPlugin, TestAtomicUpdateErrorCases, TestFieldResource, SuggesterWFSTTest, NotRequiredUniqueKeyTest, TestCodecSupport, RequiredFieldsTest, TestRandomFaceting, BadCopyFieldTest, StressHdfsTest, TestFiltering, TestReloadAndDeleteDocs, TestSolr4Spatial, TestDistribDocBasedVersion, DirectUpdateHandlerTest, TestUtils, DistributedDebugComponentTest, TestJmxIntegration, SolrRequestParserTest, DateFieldTest, ChaosMonkeyNothingIsSafeTest, DisMaxRequestHandlerTest, CoreAdminCreateDiscoverTest, RemoteQueryErrorTest, BlockCacheTest, TestImplicitCoreProperties, TestSolrJ, DeleteReplicaTest, ConvertedLegacyTest, TestRangeQuery, MinimalSchemaTest, TestDistributedMissingSort, ShardSplitTest, PingRequestHandlerTest, LeaderElectionIntegrationTest, TestSweetSpotSimilarityFactory, XsltUpdateRequestHandlerTest, TestFieldTypeResource, PrimUtilsTest, CurrencyFieldXmlFileTest, SortByFunctionTest, TestCoreDiscovery, TestAnalyzeInfixSuggestions, TestPhraseSuggestions, TestUpdate, DistributedQueryComponentCustomSortTest, TestSchemaSimilarityResource, TestDistributedSearch, ChaosMonkeySafeLeaderTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=ChaosMonkeySafeLeaderTest -Dtests.seed=C6F54B120A1E6EE9 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=th_TH_TH_#u-nu-thai -Dtests.timezone=America/Nome -Dtests.file.encoding=UTF-8
   [junit4] ERROR   0.00s J1 | ChaosMonkeySafeLeaderTest (suite) <<<
   [junit4]    > Throwable #1: java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([C6F54B120A1E6EE9]:0)Throwable #2: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=3103, name=RecoveryThread, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]    > Caused by: java.lang.AssertionError: file _1.cfs does not exist
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([C6F54B120A1E6EE9]:0)
   [junit4]    > 	at org.apache.lucene.index.IndexWriter.filesExist(IndexWriter.java:4390)
   [junit4]    > 	at org.apache.lucene.index.IndexWriter.startCommit(IndexWriter.java:4456)
   [junit4]    > 	at org.apache.lucene.index.IndexWriter.prepareCommitInternal(IndexWriter.java:2953)
   [junit4]    > 	at org.apache.lucene.index.IndexWriter.commitInternal(IndexWriter.java:3049)
   [junit4]    > 	at org.apache.lucene.index.IndexWriter.commit(IndexWriter.java:3016)
   [junit4]    > 	at org.apache.solr.update.DirectUpdateHandler2.commit(DirectUpdateHandler2.java:578)
   [junit4]    > 	at org.apache.solr.cloud.RecoveryStrategy.doRecovery(RecoveryStrategy.java:396)
   [junit4]    > 	at org.apache.solr.cloud.RecoveryStrategy.run(RecoveryStrategy.java:247)
   [junit4] Completed on J1 in 7226.28s, 1 test, 3 errors <<< FAILURES!

[...truncated 32 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/build.xml:459: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/build.xml:452: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/solr/common-build.xml:499: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/lucene/common-build.xml:1278: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.7-Linux/lucene/common-build.xml:911: There were test failures: 365 suites, 1570 tests, 2 suite-level errors, 1 error, 60 ignored (7 assumptions)

Total time: 163 minutes 31 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/ibm-j9-jdk7 -Xjit:exclude={org/apache/lucene/util/fst/FST.pack(IIF)Lorg/apache/lucene/util/fst/FST;}
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure