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/02/20 05:23:20 UTC

[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.7.0_60-ea-b04) - Build # 9532 - Still Failing!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/9532/
Java: 32bit/jdk1.7.0_60-ea-b04 -client -XX:+UseG1GC

2 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([E6427C4D79E850F1]:0)


FAILED:  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([E6427C4D79E850F1]:0)




Build Log:
[...truncated 10981 lines...]
   [junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
   [junit4]   2> 294403 T739 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
   [junit4]   2> 294403 T739 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /g/jw
   [junit4]   2> 294407 T739 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solrtest-ChaosMonkeySafeLeaderTest-1392862966525
   [junit4]   2> 294408 T739 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 294408 T740 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 294508 T739 oasc.ZkTestServer.run start zk server on port:43367
   [junit4]   2> 294509 T739 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 294542 T746 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1dcfc13 name:ZooKeeperConnection Watcher:127.0.0.1:43367 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 294542 T739 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 294542 T739 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 294546 T739 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 294548 T748 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b65496 name:ZooKeeperConnection Watcher:127.0.0.1:43367/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 294548 T739 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 294549 T739 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 294551 T739 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 294553 T739 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 294555 T739 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 294558 T739 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 294559 T739 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 294599 T739 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
   [junit4]   2> 294600 T739 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 294637 T739 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 294638 T739 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 294641 T739 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 294642 T739 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 294644 T739 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 294645 T739 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 294649 T739 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 294649 T739 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 294651 T739 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 294652 T739 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 294654 T739 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 294655 T739 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 294657 T739 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 294658 T739 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 294660 T739 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 294661 T739 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 294663 T739 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 294664 T739 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 294757 T739 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 294760 T739 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57963
   [junit4]   2> 294760 T739 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 294761 T739 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 294761 T739 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392862966792
   [junit4]   2> 294762 T739 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392862966792/'
   [junit4]   2> 294774 T739 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392862966792/solr.xml
   [junit4]   2> 294850 T739 oasc.CoreContainer.<init> New CoreContainer 21186385
   [junit4]   2> 294851 T739 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392862966792/]
   [junit4]   2> 294852 T739 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 294853 T739 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 294853 T739 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 294854 T739 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 294854 T739 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 294854 T739 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 294855 T739 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 294855 T739 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 294855 T739 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 294858 T739 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 294858 T739 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 294858 T739 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 294859 T739 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43367/solr
   [junit4]   2> 294859 T739 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 294860 T739 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 294861 T759 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ff4bcd name:ZooKeeperConnection Watcher:127.0.0.1:43367 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 294862 T739 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 294864 T739 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 294865 T761 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a7f33 name:ZooKeeperConnection Watcher:127.0.0.1:43367/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 294865 T739 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 294867 T739 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 294869 T739 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 294872 T739 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 294873 T739 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57963_g%2Fjw
   [junit4]   2> 294885 T739 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57963_g%2Fjw
   [junit4]   2> 294900 T739 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 294902 T739 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 294906 T739 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:57963_g%2Fjw
   [junit4]   2> 294906 T739 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 294908 T739 oasc.Overseer.start Overseer (id=91282667374379011-127.0.0.1:57963_g%2Fjw-n_0000000000) starting
   [junit4]   2> 294911 T739 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 294913 T763 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 294915 T739 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 294915 T763 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 294918 T739 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 294921 T739 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 294924 T762 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 294927 T764 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 294928 T764 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 294929 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 294929 T764 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 294930 T762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 294931 T762 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:57963/g/jw",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:57963_g%2Fjw",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 294931 T762 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 294931 T762 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 294933 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 294934 T761 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> 295930 T764 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 295930 T764 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392862966792/collection1
   [junit4]   2> 295930 T764 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 295931 T764 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 295931 T764 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 295932 T764 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 295932 T764 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392862966792/collection1/'
   [junit4]   2> 295933 T764 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392862966792/collection1/lib/classes/' to classloader
   [junit4]   2> 295933 T764 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392862966792/collection1/lib/README' to classloader
   [junit4]   2> 295964 T764 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 295994 T764 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 295995 T764 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 296003 T764 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 296284 T764 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 296287 T764 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 296288 T764 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 296291 T764 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 296308 T764 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 296314 T764 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392862966792/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/control/data/
   [junit4]   2> 296314 T764 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@14290e2
   [junit4]   2> 296315 T764 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/control/data
   [junit4]   2> 296315 T764 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/control/data/index/
   [junit4]   2> 296315 T764 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 296316 T764 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/control/data/index
   [junit4]   2> 296316 T764 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=26, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.42302593417648215]
   [junit4]   2> 296319 T764 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/control/data/index,segFN=segments_1,generation=1}
   [junit4]   2> 296320 T764 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 296322 T764 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 296323 T764 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 296323 T764 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 296323 T764 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 296323 T764 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 296323 T764 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 296324 T764 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 296324 T764 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 296324 T764 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 296325 T764 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 296325 T764 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 296325 T764 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 296326 T764 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 296326 T764 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 296326 T764 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 296327 T764 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 296327 T764 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 296330 T764 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 296332 T764 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 296332 T764 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 296332 T764 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=96.0458984375, floorSegmentMB=0.5322265625, forceMergeDeletesPctAllowed=0.6630555922421633, segmentsPerTier=13.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6832137714827566
   [junit4]   2> 296333 T764 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/control/data/index,segFN=segments_1,generation=1}
   [junit4]   2> 296334 T764 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 296334 T764 oass.SolrIndexSearcher.<init> Opening Searcher@696108[collection1] main
   [junit4]   2> 296338 T764 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 296339 T739 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 296339 T739 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 296339 T765 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@696108[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 296339 T768 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57963/g/jw collection:control_collection shard:shard1
   [junit4]   2> 296341 T739 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 296342 T770 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b8f229 name:ZooKeeperConnection Watcher:127.0.0.1:43367/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 296342 T768 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 296342 T739 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 296344 T739 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 296346 T739 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 296348 T768 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 296350 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 296350 T768 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 296351 T768 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C328 name=collection1 org.apache.solr.core.SolrCore@2f9923 url=http://127.0.0.1:57963/g/jw/collection1 node=127.0.0.1:57963_g%2Fjw C328_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:57963/g/jw, core=collection1, node_name=127.0.0.1:57963_g%2Fjw}
   [junit4]   2> 296351 T768 C328 P57963 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57963/g/jw/collection1/
   [junit4]   2> 296351 T768 C328 P57963 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 296351 T768 C328 P57963 oasc.SyncStrategy.syncToMe http://127.0.0.1:57963/g/jw/collection1/ has no replicas
   [junit4]   2> 296352 T768 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57963/g/jw/collection1/ shard1
   [junit4]   2> 296352 T768 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 296353 T762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 296359 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 296362 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 296365 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 296434 T739 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 296435 T739 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 296436 T739 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:39275
   [junit4]   2> 296437 T739 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 296437 T739 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 296439 T739 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392862968465
   [junit4]   2> 296439 T739 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392862968465/'
   [junit4]   2> 296451 T739 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392862968465/solr.xml
   [junit4]   2> 296468 T770 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> 296468 T761 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> 296482 T739 oasc.CoreContainer.<init> New CoreContainer 30577886
   [junit4]   2> 296482 T739 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392862968465/]
   [junit4]   2> 296483 T739 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 296484 T739 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 296484 T739 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 296484 T739 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 296484 T739 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 296485 T739 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 296485 T739 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 296485 T739 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 296486 T739 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 296488 T739 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 296488 T739 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 296489 T739 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 296489 T739 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43367/solr
   [junit4]   2> 296489 T739 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 296490 T739 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 296492 T781 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2ba3c3 name:ZooKeeperConnection Watcher:127.0.0.1:43367 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 296492 T739 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 296494 T739 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 296495 T783 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11ce827 name:ZooKeeperConnection Watcher:127.0.0.1:43367/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 296495 T739 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 296499 T739 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 296513 T768 oasc.ZkController.register We are http://127.0.0.1:57963/g/jw/collection1/ and leader is http://127.0.0.1:57963/g/jw/collection1/
   [junit4]   2> 296513 T768 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57963/g/jw
   [junit4]   2> 296513 T768 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 296513 T768 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 296514 T768 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 296515 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 296515 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 296515 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 296515 T768 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 296517 T762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 296518 T762 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:57963/g/jw",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:57963_g%2Fjw",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 296520 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 296623 T783 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> 296623 T761 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> 296623 T770 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> 297501 T739 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:39275_g%2Fjw
   [junit4]   2> 297503 T739 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:39275_g%2Fjw
   [junit4]   2> 297506 T761 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 297506 T783 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 297506 T770 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 297512 T784 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 297512 T784 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 297513 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 297513 T784 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 297513 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 297514 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 297515 T762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 297515 T762 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:39275/g/jw",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:39275_g%2Fjw",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 297515 T762 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
   [junit4]   2> 297516 T762 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 297518 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 297667 T783 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> 297667 T761 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> 297667 T770 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> 298514 T784 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 298514 T784 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392862968465/collection1
   [junit4]   2> 298514 T784 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 298515 T784 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 298515 T784 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 298516 T784 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 298517 T784 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392862968465/collection1/'
   [junit4]   2> 298517 T784 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392862968465/collection1/lib/classes/' to classloader
   [junit4]   2> 298518 T784 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392862968465/collection1/lib/README' to classloader
   [junit4]   2> 298550 T784 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 298579 T784 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 298580 T784 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 298588 T784 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 298892 T784 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 298895 T784 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 298896 T784 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 298900 T784 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 298918 T784 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 298918 T784 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392862968465/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty1/
   [junit4]   2> 298919 T784 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@14290e2
   [junit4]   2> 298919 T784 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty1
   [junit4]   2> 298919 T784 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty1/index/
   [junit4]   2> 298920 T784 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 298921 T784 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty1/index
   [junit4]   2> 298921 T784 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=26, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.42302593417648215]
   [junit4]   2> 298950 T784 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty1/index,segFN=segments_1,generation=1}
   [junit4]   2> 298951 T784 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 298954 T784 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 298954 T784 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 298954 T784 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 298955 T784 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 298955 T784 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 298955 T784 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 298955 T784 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 298956 T784 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 298956 T784 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 298957 T784 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 298957 T784 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 298957 T784 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 298958 T784 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 298958 T784 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 298958 T784 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 298959 T784 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 298960 T784 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 298962 T784 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 298964 T784 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 298964 T784 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 298965 T784 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=96.0458984375, floorSegmentMB=0.5322265625, forceMergeDeletesPctAllowed=0.6630555922421633, segmentsPerTier=13.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6832137714827566
   [junit4]   2> 298966 T784 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty1/index,segFN=segments_1,generation=1}
   [junit4]   2> 298966 T784 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 298967 T784 oass.SolrIndexSearcher.<init> Opening Searcher@98cb7b[collection1] main
   [junit4]   2> 298971 T785 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@98cb7b[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 298974 T784 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 298975 T739 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 298976 T739 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 298975 T788 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:39275/g/jw collection:collection1 shard:shard1
   [junit4]   2> 298977 T788 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 298983 T788 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 298984 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 298985 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 298985 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 298985 T788 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 298986 T788 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C329 name=collection1 org.apache.solr.core.SolrCore@bcc86c url=http://127.0.0.1:39275/g/jw/collection1 node=127.0.0.1:39275_g%2Fjw C329_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:39275/g/jw, core=collection1, node_name=127.0.0.1:39275_g%2Fjw}
   [junit4]   2> 298986 T788 C329 P39275 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:39275/g/jw/collection1/
   [junit4]   2> 298986 T788 C329 P39275 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 298986 T788 C329 P39275 oasc.SyncStrategy.syncToMe http://127.0.0.1:39275/g/jw/collection1/ has no replicas
   [junit4]   2> 298987 T788 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:39275/g/jw/collection1/ shard1
   [junit4]   2> 298987 T788 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 298988 T762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 298991 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 298993 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 298997 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 299080 T739 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 299081 T739 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 299083 T739 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:37755
   [junit4]   2> 299084 T739 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 299084 T739 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 299085 T739 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392862971094
   [junit4]   2> 299085 T739 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392862971094/'
   [junit4]   2> 299098 T739 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392862971094/solr.xml
   [junit4]   2> 299099 T761 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> 299099 T770 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> 299100 T783 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> 299138 T739 oasc.CoreContainer.<init> New CoreContainer 7548654
   [junit4]   2> 299138 T739 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392862971094/]
   [junit4]   2> 299139 T739 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 299139 T739 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 299140 T739 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 299140 T739 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 299141 T739 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 299141 T739 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 299141 T739 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 299142 T739 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 299142 T739 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 299144 T739 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 299144 T788 oasc.ZkController.register We are http://127.0.0.1:39275/g/jw/collection1/ and leader is http://127.0.0.1:39275/g/jw/collection1/
   [junit4]   2> 299145 T739 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 299145 T788 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:39275/g/jw
   [junit4]   2> 299146 T788 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 299146 T788 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 299146 T788 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 299146 T739 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 299147 T739 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43367/solr
   [junit4]   2> 299147 T739 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 299148 T739 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 299157 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 299157 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 299157 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 299159 T799 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@121a462 name:ZooKeeperConnection Watcher:127.0.0.1:43367 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 299159 T788 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 299160 T739 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 299160 T762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 299162 T762 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:39275/g/jw",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:39275_g%2Fjw",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 299163 T739 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 299164 T801 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e9f4c9 name:ZooKeeperConnection Watcher:127.0.0.1:43367/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 299164 T739 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 299165 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 299168 T739 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 299279 T801 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> 299279 T783 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> 299279 T770 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> 299279 T761 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> 300172 T739 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37755_g%2Fjw
   [junit4]   2> 300174 T739 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37755_g%2Fjw
   [junit4]   2> 300178 T783 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 300178 T770 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 300178 T761 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 300179 T801 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 300184 T802 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 300185 T802 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 300186 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 300186 T802 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 300186 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 300186 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 300188 T762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 300188 T762 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:37755/g/jw",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:37755_g%2Fjw",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 300189 T762 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 300189 T762 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 300191 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 300347 T801 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> 300347 T770 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> 300347 T783 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> 300347 T761 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> 301186 T802 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 301187 T802 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392862971094/collection1
   [junit4]   2> 301187 T802 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 301188 T802 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 301188 T802 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 301189 T802 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 301189 T802 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392862971094/collection1/'
   [junit4]   2> 301190 T802 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392862971094/collection1/lib/classes/' to classloader
   [junit4]   2> 301191 T802 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392862971094/collection1/lib/README' to classloader
   [junit4]   2> 301237 T802 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 301273 T802 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 301274 T802 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 301282 T802 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 301549 T802 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 301551 T802 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 301553 T802 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 301556 T802 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 301573 T802 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 301574 T802 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392862971094/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty2/
   [junit4]   2> 301574 T802 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@14290e2
   [junit4]   2> 301574 T802 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty2
   [junit4]   2> 301575 T802 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty2/index/
   [junit4]   2> 301575 T802 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 301575 T802 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty2/index
   [junit4]   2> 301576 T802 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=26, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.42302593417648215]
   [junit4]   2> 301579 T802 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty2/index,segFN=segments_1,generation=1}
   [junit4]   2> 301579 T802 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 301582 T802 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 301583 T802 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 301583 T802 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 301583 T802 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 301583 T802 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 301584 T802 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 301584 T802 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 301584 T802 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 301584 T802 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 301585 T802 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 301586 T802 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 301586 T802 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 301586 T802 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 301587 T802 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 301587 T802 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 301587 T802 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 301588 T802 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 301590 T802 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 301592 T802 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 301593 T802 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 301594 T802 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=96.0458984375, floorSegmentMB=0.5322265625, forceMergeDeletesPctAllowed=0.6630555922421633, segmentsPerTier=13.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6832137714827566
   [junit4]   2> 301595 T802 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty2/index,segFN=segments_1,generation=1}
   [junit4]   2> 301595 T802 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 301595 T802 oass.SolrIndexSearcher.<init> Opening Searcher@caf6bf[collection1] main
   [junit4]   2> 301600 T803 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@caf6bf[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 301603 T802 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 301604 T739 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 301604 T739 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 301604 T806 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:37755/g/jw collection:collection1 shard:shard2
   [junit4]   2> 301606 T806 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 301611 T806 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 301613 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 301614 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 301614 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 301615 T806 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 301615 T762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 301615 T806 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C330 name=collection1 org.apache.solr.core.SolrCore@25570e url=http://127.0.0.1:37755/g/jw/collection1 node=127.0.0.1:37755_g%2Fjw C330_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:37755/g/jw, core=collection1, node_name=127.0.0.1:37755_g%2Fjw}
   [junit4]   2> 301616 T806 C330 P37755 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:37755/g/jw/collection1/
   [junit4]   2> 301616 T806 C330 P37755 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 301617 T806 C330 P37755 oasc.SyncStrategy.syncToMe http://127.0.0.1:37755/g/jw/collection1/ has no replicas
   [junit4]   2> 301617 T806 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:37755/g/jw/collection1/ shard2
   [junit4]   2> 301617 T806 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 301619 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 301622 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 301625 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 301693 T739 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
   [junit4]   2> 301694 T739 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 301696 T739 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:46294
   [junit4]   2> 301697 T739 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 301697 T739 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 301697 T739 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392862973723
   [junit4]   2> 301698 T739 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392862973723/'
   [junit4]   2> 301711 T739 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392862973723/solr.xml
   [junit4]   2> 301729 T761 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> 301729 T801 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> 301729 T783 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> 301729 T770 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> 301757 T739 oasc.CoreContainer.<init> New CoreContainer 6612675
   [junit4]   2> 301757 T739 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392862973723/]
   [junit4]   2> 301759 T739 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 301759 T739 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 301760 T739 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 301760 T739 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 301761 T739 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 301761 T739 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 301762 T739 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 301762 T739 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 301763 T739 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 301765 T739 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 301765 T739 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 301766 T739 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 301766 T739 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:43367/solr
   [junit4]   2> 301766 T739 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 301767 T739 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 301769 T817 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6a1bcb name:ZooKeeperConnection Watcher:127.0.0.1:43367 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 301770 T739 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 301772 T739 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 301774 T806 oasc.ZkController.register We are http://127.0.0.1:37755/g/jw/collection1/ and leader is http://127.0.0.1:37755/g/jw/collection1/
   [junit4]   2> 301774 T806 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:37755/g/jw
   [junit4]   2> 301774 T819 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d3d9ce name:ZooKeeperConnection Watcher:127.0.0.1:43367/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 301774 T806 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 301774 T739 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 301774 T806 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 301775 T806 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 301777 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 301777 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 301777 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 301777 T806 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 301779 T762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 301779 T762 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:37755/g/jw",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:37755_g%2Fjw",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 301781 T739 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 301782 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 301885 T770 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> 301885 T783 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> 301885 T801 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> 301885 T761 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> 301885 T819 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> 302785 T739 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46294_g%2Fjw
   [junit4]   2> 302786 T739 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:46294_g%2Fjw
   [junit4]   2> 302789 T770 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 302789 T801 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 302790 T819 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 302790 T761 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 302789 T783 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 302796 T820 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 302796 T820 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 302798 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 302798 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 302798 T820 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 302798 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 302799 T762 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 302800 T762 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:46294/g/jw",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:46294_g%2Fjw",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 302800 T762 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 302800 T762 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 302859 T761 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 302962 T783 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> 302962 T761 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> 302962 T770 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> 302962 T801 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> 302962 T819 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> 303798 T820 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 303799 T820 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392862973723/collection1
   [junit4]   2> 303799 T820 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 303800 T820 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 303800 T820 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 303802 T820 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 303802 T820 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392862973723/collection1/'
   [junit4]   2> 303803 T820 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392862973723/collection1/lib/classes/' to classloader
   [junit4]   2> 303803 T820 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392862973723/collection1/lib/README' to classloader
   [junit4]   2> 303848 T820 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 303877 T820 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 303879 T820 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 303887 T820 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 304159 T820 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 304162 T820 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 304163 T820 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 304166 T820 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 304185 T820 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 304185 T820 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392862973723/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty3/
   [junit4]   2> 304185 T820 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@14290e2
   [junit4]   2> 304186 T820 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty3
   [junit4]   2> 304186 T820 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty3/index/
   [junit4]   2> 304186 T820 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 304187 T820 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty3/index
   [junit4]   2> 304188 T820 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=26, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.42302593417648215]
   [junit4]   2> 304190 T820 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty3/index,segFN=segments_1,generation=1}
   [junit4]   2> 304191 T820 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 304194 T820 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 304194 T820 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 304194 T820 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 304195 T820 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 304195 T820 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 304195 T820 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 304195 T820 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 304196 T820 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 304196 T820 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 304197 T820 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 304197 T820 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 304197 T820 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 304198 T820 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 304198 T820 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 304198 T820 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 304199 T820 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 304200 T820 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 304202 T820 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 304204 T820 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 304204 T820 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 304205 T820 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=33, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=96.0458984375, floorSegmentMB=0.5322265625, forceMergeDeletesPctAllowed=0.6630555922421633, segmentsPerTier=13.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.6832137714827566
   [junit4]   2> 304206 T820 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392862966525/jetty3/index,segFN=segments_1,generation=1}
   [junit4]   2> 304206 T820 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 304207 T820 oass.SolrIndexSearcher.<init> Opening Searcher@1d7f550[collection1] main
   [junit4]   2> 304211 T821 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1d7f550[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 304214 T820 oasc.CoreContainer.regi

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

  [junit4]   2> 	        at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:78)
   [junit4]   2> 	        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
   [junit4]   2> 	        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
   [junit4]   2> 	        at org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:569)
   [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:744)
   [junit4]   2> 	  68) Thread[id=840, name=Thread-341, state=WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at java.lang.Object.wait(Native Method)
   [junit4]   2> 	        at java.lang.Object.wait(Object.java:503)
   [junit4]   2> 	        at org.apache.solr.core.CloserThread.run(CoreContainer.java:1018)
   [junit4]   2> 	  69) Thread[id=1072, name=qtp18553588-1072 Acceptor0 SelectChannelConnector@127.0.0.1:49910, state=BLOCKED, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at org.eclipse.jetty.server.nio.SelectChannelConnector.accept(SelectChannelConnector.java:102)
   [junit4]   2> 	        at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:938)
   [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:744)
   [junit4]   2> 	  70) Thread[id=1050, name=Thread-440-SendThread(localhost.localdomain:43367), state=TIMED_WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at java.lang.Thread.sleep(Native Method)
   [junit4]   2> 	        at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:984)
   [junit4]   2> 	  71) Thread[id=907, name=qtp30589138-907 Acceptor1 SelectChannelConnector@127.0.0.1:59940, state=BLOCKED, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at org.eclipse.jetty.server.nio.SelectChannelConnector.getConnection(SelectChannelConnector.java:160)
   [junit4]   2> 	        at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:934)
   [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:744)
   [junit4]   2> 	  72) Thread[id=883, name=HashSessionScavenger-18, state=TIMED_WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at java.lang.Object.wait(Native Method)
   [junit4]   2> 	        at java.util.TimerThread.mainLoop(Timer.java:552)
   [junit4]   2> 	        at java.util.TimerThread.run(Timer.java:505)
   [junit4]   2> 	  73) Thread[id=1013, name=commitScheduler-591-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:186)
   [junit4]   2> 	        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
   [junit4]   2> 	        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1079)
   [junit4]   2> 	        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 	  74) Thread[id=1086, name=Thread-472, state=WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at java.lang.Object.wait(Native Method)
   [junit4]   2> 	        at java.lang.Object.wait(Object.java:503)
   [junit4]   2> 	        at org.apache.solr.core.CloserThread.run(CoreContainer.java:1018)
   [junit4]   2> 	  75) Thread[id=966, name=qtp1966647-966 Acceptor0 SelectChannelConnector@127.0.0.1:52162, state=BLOCKED, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at org.eclipse.jetty.server.nio.SelectChannelConnector.accept(SelectChannelConnector.java:102)
   [junit4]   2> 	        at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:938)
   [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:744)
   [junit4]   2> 	  76) Thread[id=886, name=qtp517760-886 Acceptor0 SelectChannelConnector@127.0.0.1:58203, state=BLOCKED, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at org.eclipse.jetty.server.nio.SelectChannelConnector.accept(SelectChannelConnector.java:102)
   [junit4]   2> 	        at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:938)
   [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:744)
   [junit4]   2> 	  77) Thread[id=826, name=qtp32456852-826 Selector0, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
   [junit4]   2> 	        at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
   [junit4]   2> 	        at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
   [junit4]   2> 	        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
   [junit4]   2> 	        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
   [junit4]   2> 	        at org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:569)
   [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:744)
   [junit4]   2> NOTE: test params are: codec=Lucene42, sim=DefaultSimilarity, locale=ar_SA, timezone=America/Aruba
   [junit4]   2> NOTE: Linux 3.8.0-35-generic i386/Oracle Corporation 1.7.0_60-ea (32-bit)/cpus=8,threads=90,free=199087048,total=324009984
   [junit4]   2> NOTE: All tests run in this JVM: [ShardSplitTest, UniqFieldsUpdateProcessorFactoryTest, DisMaxRequestHandlerTest, StandardRequestHandlerTest, TestPartialUpdateDeduplication, TestFieldTypeCollectionResource, CachingDirectoryFactoryTest, TestIndexingPerformance, LeaderElectionIntegrationTest, HdfsCollectionsAPIDistributedZkTest, TestReloadAndDeleteDocs, TestNonDefinedSimilarityFactory, DirectSolrSpellCheckerTest, TestBinaryResponseWriter, SolrPluginUtilsTest, PreAnalyzedFieldTest, TestCSVResponseWriter, DistributedQueryComponentCustomSortTest, ConvertedLegacyTest, ZkSolrClientTest, TestIBSimilarityFactory, TestFastWriter, TestSolrCoreProperties, TimeZoneUtilsTest, TestCoreDiscovery, TestXIncludeConfig, TestIndexSearcher, TestCollationFieldDocValues, ChaosMonkeySafeLeaderTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=ChaosMonkeySafeLeaderTest -Dtests.seed=E6427C4D79E850F1 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ar_SA -Dtests.timezone=America/Aruba -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([E6427C4D79E850F1]:0)
   [junit4] Completed on J1 in 7225.32s, 1 test, 2 errors <<< FAILURES!

[...truncated 203 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:453: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:433: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:491: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1268: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:901: There were test failures: 372 suites, 1604 tests, 1 suite-level error, 1 error, 254 ignored (5 assumptions)

Total time: 151 minutes 19 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_60-ea-b04 -client -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure