lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-trunk-Linux (64bit/jdk1.9.0-ea-b34) - Build # 11824 - Failure!
Date Mon, 29 Dec 2014 01:55:33 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/11824/
Java: 64bit/jdk1.9.0-ea-b34 -XX:-UseCompressedOops -XX:+UseG1GC (asserts: true)

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([78D62EC33B461E33]: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([78D62EC33B461E33]:0)




Build Log:
[...truncated 10414 lines...]
   [junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/init-core-data-001
   [junit4]   2> 1691221 T5088 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (false) and clientAuth (false)
   [junit4]   2> 1691221 T5088 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 1691223 T5088 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> 1691224 T5088 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1691224 T5089 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1691324 T5088 oasc.ZkTestServer.run start zk server on port:45567
   [junit4]   2> 1691325 T5088 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 1691325 T5088 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1691328 T5096 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@733c650b name:ZooKeeperConnection Watcher:127.0.0.1:45567 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1691328 T5088 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1691329 T5088 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 1691329 T5088 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1691332 T5088 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 1691333 T5088 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1691333 T5099 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7099daea name:ZooKeeperConnection Watcher:127.0.0.1:45567/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1691334 T5088 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1691334 T5088 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 1691334 T5088 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 1691336 T5088 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 1691338 T5088 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 1691339 T5088 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 1691340 T5088 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 1691340 T5088 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 1691342 T5088 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
   [junit4]   2> 1691342 T5088 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 1691343 T5088 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1691344 T5088 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1691345 T5088 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 1691345 T5088 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 1691346 T5088 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 1691347 T5088 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 1691348 T5088 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 1691348 T5088 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 1691349 T5088 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 1691349 T5088 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 1691350 T5088 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1691350 T5088 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1691351 T5088 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1691351 T5088 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1691352 T5088 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 1691353 T5088 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 1691353 T5088 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 1691354 T5088 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 1691593 T5088 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1691597 T5088 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:45168
   [junit4]   2> 1691598 T5088 oass.SolrDispatchFilter.init SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@4e0e2f2a
   [junit4]   2> 1691598 T5088 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1691598 T5088 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-002
   [junit4]   2> 1691598 T5088 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-002/'
   [junit4]   2> 1691609 T5088 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-002/solr.xml
   [junit4]   2> 1691618 T5088 oasc.CoreContainer.<init> New CoreContainer 46958647
   [junit4]   2> 1691618 T5088 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-002/]
   [junit4]   2> 1691619 T5088 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1691619 T5088 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1691619 T5088 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1691619 T5088 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1691619 T5088 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
   [junit4]   2> 1691620 T5088 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1691620 T5088 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1691620 T5088 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1691620 T5088 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1691621 T5088 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1691621 T5088 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
   [junit4]   2> 1691621 T5088 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1691621 T5088 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1691622 T5088 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1691622 T5088 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:45567/solr
   [junit4]   2> 1691622 T5088 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1691622 T5088 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 1691623 T5088 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1691624 T5111 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@769452e5 name:ZooKeeperConnection Watcher:127.0.0.1:45567 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1691625 T5088 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1691626 T5088 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 1691628 T5088 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1691629 T5114 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@400284c name:ZooKeeperConnection Watcher:127.0.0.1:45567/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1691629 T5088 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1691630 T5088 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1691633 T5088 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1691636 T5088 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 1691639 T5088 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 1691641 T5088 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 1691645 T5088 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1691646 T5088 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45168_
   [junit4]   2> 1691647 T5088 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:45168_
   [junit4]   2> 1691650 T5088 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1691652 T5088 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1691654 T5088 oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 1691656 T5088 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:45168_
   [junit4]   2> 1691656 T5088 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1691658 T5088 oasc.Overseer.start Overseer (id=93048725992570883-127.0.0.1:45168_-n_0000000000) starting
   [junit4]   2> 1691661 T5088 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1691668 T5088 oasc.OverseerAutoReplicaFailoverThread.<init> Starting OverseerAutoReplicaFailoverThread autoReplicaFailoverWorkLoopDelay=10000 autoReplicaFailoverWaitAfterExpiration=30000 autoReplicaFailoverBadNodeExpiration=60000
   [junit4]   2> 1691669 T5116 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1691670 T5088 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1691673 T5088 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1691674 T5088 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1691680 T5115 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1691682 T5118 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 1691682 T5118 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1691683 T5114 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1691683 T5118 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1691687 T5115 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 0, message = {
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:45168",
   [junit4]   2> 	  "node_name":"127.0.0.1:45168_",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "operation":"state"} current state version: 0
   [junit4]   2> 1691687 T5115 oasco.ReplicaMutator.updateState Update state numShards=1 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:45168",
   [junit4]   2> 	  "node_name":"127.0.0.1:45168_",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 1691688 T5115 oasco.ClusterStateMutator.createCollection building a new cName: control_collection
   [junit4]   2> 1691688 T5115 oasco.ReplicaMutator.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1691690 T5114 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> 1692684 T5118 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1692685 T5118 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 1692686 T5118 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1692686 T5118 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 1692688 T5118 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1692688 T5118 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-002/collection1/'
   [junit4]   2> 1692689 T5118 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-002/collection1/lib/.svn/' to classloader
   [junit4]   2> 1692689 T5118 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-002/collection1/lib/classes/' to classloader
   [junit4]   2> 1692690 T5118 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-002/collection1/lib/README' to classloader
   [junit4]   2> 1692705 T5118 oasc.ZkController.watchZKConfDir watch zkdir /configs/conf1
   [junit4]   2> 1692708 T5118 oasc.Config.<init> loaded config solrconfig.xml with version 0 
   [junit4]   2> 1692730 T5118 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 1692739 T5118 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1692740 T5118 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 1692744 T5118 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1692818 T5118 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1692819 T5118 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1692820 T5118 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1692823 T5118 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1692835 T5118 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 1692836 T5118 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 1692836 T5118 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-002/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-001/control/data/
   [junit4]   2> 1692836 T5118 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7761cb42
   [junit4]   2> 1692837 T5118 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-001/control/data
   [junit4]   2> 1692837 T5118 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-001/control/data/index/
   [junit4]   2> 1692837 T5118 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-001/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1692838 T5118 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-001/control/data/index
   [junit4]   2> 1692838 T5118 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=50, maxMergeAtOnceExplicit=44, maxMergedSegmentMB=37.7763671875, floorSegmentMB=2.0107421875, forceMergeDeletesPctAllowed=22.637801835175402, segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7411699806539382
   [junit4]   2> 1692920 T5118 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/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-001/control/data/index,segFN=segments_1,generation=1}
   [junit4]   2> 1692920 T5118 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1692924 T5118 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1692925 T5118 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1692925 T5118 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1692925 T5118 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1692926 T5118 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1692926 T5118 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1692926 T5118 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1692927 T5118 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1692927 T5118 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1692928 T5118 oasc.RequestHandlers.initHandlersFromConfig created /update: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 1692928 T5118 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 1692929 T5118 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 1692929 T5118 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 1692930 T5118 oasc.RequestHandlers.initHandlersFromConfig created /config: org.apache.solr.handler.SolrConfigHandler
   [junit4]   2> 1692930 T5118 oasc.RequestHandlers.initHandlersFromConfig created /schema: org.apache.solr.handler.SchemaHandler
   [junit4]   2> 1692931 T5118 oasc.RequestHandlers.initHandlersFromConfig created /replication: org.apache.solr.handler.ReplicationHandler
   [junit4]   2> 1692931 T5118 oasc.RequestHandlers.initHandlersFromConfig created /get: org.apache.solr.handler.RealTimeGetHandler
   [junit4]   2> 1692932 T5118 oasc.RequestHandlers.initHandlersFromConfig created /admin/luke: org.apache.solr.handler.admin.LukeRequestHandler
   [junit4]   2> 1692932 T5118 oasc.RequestHandlers.initHandlersFromConfig created /admin/system: org.apache.solr.handler.admin.SystemInfoHandler
   [junit4]   2> 1692933 T5118 oasc.RequestHandlers.initHandlersFromConfig created /admin/mbeans: org.apache.solr.handler.admin.SolrInfoMBeanHandler
   [junit4]   2> 1692933 T5118 oasc.RequestHandlers.initHandlersFromConfig created /admin/plugins: org.apache.solr.handler.admin.PluginInfoHandler
   [junit4]   2> 1692934 T5118 oasc.RequestHandlers.initHandlersFromConfig created /admin/threads: org.apache.solr.handler.admin.ThreadDumpHandler
   [junit4]   2> 1692934 T5118 oasc.RequestHandlers.initHandlersFromConfig created /admin/properties: org.apache.solr.handler.admin.PropertiesRequestHandler
   [junit4]   2> 1692935 T5118 oasc.RequestHandlers.initHandlersFromConfig created /admin/logging: org.apache.solr.handler.admin.LoggingHandler
   [junit4]   2> 1692935 T5118 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: org.apache.solr.handler.PingRequestHandler
   [junit4]   2> 1692936 T5118 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1692936 T5118 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1692937 T5118 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 1692940 T5118 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1692941 T5118 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1692941 T5118 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1692942 T5118 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1692943 T5118 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 1692943 T5118 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1692943 T5118 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1692944 T5118 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=31, maxMergeAtOnceExplicit=23, maxMergedSegmentMB=42.5185546875, floorSegmentMB=0.412109375, forceMergeDeletesPctAllowed=5.14195774493436, segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 1692944 T5118 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/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-001/control/data/index,segFN=segments_1,generation=1}
   [junit4]   2> 1692945 T5118 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1692945 T5118 oass.SolrIndexSearcher.<init> Opening Searcher@250ead58[collection1] main
   [junit4]   2> 1692945 T5118 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 1692946 T5118 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1692946 T5118 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 1692947 T5118 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1692947 T5118 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 1692947 T5118 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1692948 T5118 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 1692948 T5118 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1692948 T5118 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 1692948 T5118 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 1692949 T5118 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1692949 T5119 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@250ead58[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1692949 T5122 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:45168 collection:control_collection shard:shard1
   [junit4]   2> 1692950 T5088 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 1692950 T5088 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1692951 T5122 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 1692951 T5088 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 1692952 T5088 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1692953 T5125 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5b00bb25 name:ZooKeeperConnection Watcher:127.0.0.1:45567/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1692953 T5088 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1692953 T5088 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 1692955 T5088 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1692956 T5122 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1692957 T5114 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1692957 T5088 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 1692958 T5122 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1692958 T5122 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 1692958 T5088 oasc.AbstractFullDistribZkTestBase.createJettys Creating collection1 with stateFormat=2
   [junit4]   2> ASYNC  NEW_CORE C1073 name=collection1 org.apache.solr.core.SolrCore@59524b4a url=http://127.0.0.1:45168/collection1 node=127.0.0.1:45168_ C1073_STATE=coll:control_collection core:collection1 props:{core=collection1, base_url=http://127.0.0.1:45168, node_name=127.0.0.1:45168_, state=down}
   [junit4]   2> 1692958 T5122 C1073 P45168 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:45168/collection1/
   [junit4]   2> 1692958 T5088 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 1692958 T5115 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection"} current state version: 1
   [junit4]   2> 1692958 T5122 C1073 P45168 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1692959 T5088 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1692959 T5122 C1073 P45168 oasc.SyncStrategy.syncToMe http://127.0.0.1:45168/collection1/ has no replicas
   [junit4]   2> 1692959 T5122 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:45168/collection1/ shard1
   [junit4]   2> 1692959 T5122 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 1692960 T5128 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5041fcd4 name:ZooKeeperConnection Watcher:127.0.0.1:45567/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1692960 T5088 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1692960 T5088 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 1692962 T5114 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1692963 T5115 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"create",
   [junit4]   2> 	  "name":"collection1",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "stateFormat":2} current state version: 1
   [junit4]   2> 1692963 T5115 oasco.ClusterStateMutator.createCollection building a new cName: collection1
   [junit4]   2> 1692964 T5114 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> 1692964 T5125 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> 1692968 T5115 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:45168",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "state":"active"} current state version: 2
   [junit4]   2> 1692969 T5115 oasco.ZkStateWriter.writePendingUpdates going to create_collection /collections/collection1/state.json
   [junit4]   2> 1692970 T5125 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> 1692973 T5129 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1692973 T5125 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> 1693014 T5122 oasc.ZkController.register We are http://127.0.0.1:45168/collection1/ and leader is http://127.0.0.1:45168/collection1/
   [junit4]   2> 1693014 T5122 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:45168
   [junit4]   2> 1693014 T5122 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1693014 T5122 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 1693014 T5122 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1693015 T5114 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1693016 T5115 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:45168",
   [junit4]   2> 	  "node_name":"127.0.0.1:45168_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "operation":"state"} current state version: 4
   [junit4]   2> 1693017 T5115 oasco.ReplicaMutator.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:45168",
   [junit4]   2> 	  "node_name":"127.0.0.1:45168_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 1693119 T5114 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> 1693119 T5125 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> 1693206 T5088 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 1693207 T5088 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1693208 T5088 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:59892
   [junit4]   2> 1693210 T5088 oass.SolrDispatchFilter.init SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@4e0e2f2a
   [junit4]   2> 1693210 T5088 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1693210 T5088 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-003
   [junit4]   2> 1693211 T5088 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-003/'
   [junit4]   2> 1693220 T5088 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/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-003/solr.xml
   [junit4]   2> 1693245 T5088 oasc.CoreContainer.<init> New CoreContainer 564571002
   [junit4]   2> 1693245 T5088 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-003/]
   [junit4]   2> 1693246 T5088 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1693246 T5088 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1693247 T5088 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1693247 T5088 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1693248 T5088 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
   [junit4]   2> 1693248 T5088 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1693249 T5088 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1693249 T5088 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1693250 T5088 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1693250 T5088 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1693251 T5088 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
   [junit4]   2> 1693251 T5088 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1693252 T5088 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1693252 T5088 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1693253 T5088 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:45567/solr
   [junit4]   2> 1693253 T5088 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1693254 T5088 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 1693255 T5088 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1693257 T5141 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ecbac3f name:ZooKeeperConnection Watcher:127.0.0.1:45567 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1693258 T5088 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1693259 T5088 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 1693262 T5088 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1693263 T5144 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5261b5c1 name:ZooKeeperConnection Watcher:127.0.0.1:45567/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1693263 T5088 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1693271 T5088 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1694276 T5088 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59892_
   [junit4]   2> 1694277 T5088 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:59892_
   [junit4]   2> 1694284 T5088 oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 1694292 T5145 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 1694292 T5145 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1694294 T5114 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1694295 T5145 oasc.ZkController.preRegister Registering watch for external collection collection1
   [junit4]   2> 1694296 T5115 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:59892",
   [junit4]   2> 	  "node_name":"127.0.0.1:59892_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"} current state version: 5
   [junit4]   2> 1694296 T5145 oascc.ZkStateReader.addZkWatch addZkWatch collection1
   [junit4]   2> 1694296 T5115 oasco.ReplicaMutator.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:59892",
   [junit4]   2> 	  "node_name":"127.0.0.1:59892_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 1694297 T5145 oascc.ZkStateReader.addZkWatch Updating collection state at /collections/collection1/state.json from ZooKeeper... 
   [junit4]   2> 1694297 T5115 oasco.ReplicaMutator.updateState Collection already exists with numShards=2
   [junit4]   2> 1694297 T5115 oasco.ReplicaMutator.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 1694298 T5145 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 0 
   [junit4]   2> 1694299 T5145 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1694401 T5115 oasco.ZkStateWriter.writePendingUpdates going to update_collection /collections/collection1/state.json version: 0
   [junit4]   2> 1694402 T5144 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... 
   [junit4]   2> 1694403 T5144 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 1 
   [junit4]   2> 1695299 T5145 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1695300 T5145 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1695301 T5145 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1695301 T5145 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1695302 T5145 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1695303 T5145 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-003/collection1/'
   [junit4]   2> 1695304 T5145 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-003/collection1/lib/.svn/' to classloader
   [junit4]   2> 1695304 T5145 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-003/collection1/lib/classes/' to classloader
   [junit4]   2> 1695305 T5145 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-003/collection1/lib/README' to classloader
   [junit4]   2> 1695322 T5145 oasc.ZkController.watchZKConfDir watch zkdir /configs/conf1
   [junit4]   2> 1695324 T5145 oasc.Config.<init> loaded config solrconfig.xml with version 0 
   [junit4]   2> 1695333 T5145 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 1695343 T5145 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1695345 T5145 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 1695349 T5145 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1695434 T5145 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1695435 T5145 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1695436 T5145 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1695439 T5145 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1695457 T5145 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 1695458 T5145 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 1695458 T5145 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-003/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-001/jetty1/
   [junit4]   2> 1695458 T5145 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7761cb42
   [junit4]   2> 1695459 T5145 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-001/jetty1
   [junit4]   2> 1695459 T5145 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-001/jetty1/index/
   [junit4]   2> 1695459 T5145 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-001/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 1695461 T5145 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-001/jetty1/index
   [junit4]   2> 1695461 T5145 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=50, maxMergeAtOnceExplicit=44, maxMergedSegmentMB=37.7763671875, floorSegmentMB=2.0107421875, forceMergeDeletesPctAllowed=22.637801835175402, segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7411699806539382
   [junit4]   2> 1695471 T5145 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/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-001/jetty1/index,segFN=segments_1,generation=1}
   [junit4]   2> 1695471 T5145 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1695473 T5145 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1695473 T5145 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1695473 T5145 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1695473 T5145 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1695473 T5145 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1695474 T5145 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1695474 T5145 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1695474 T5145 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1695474 T5145 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1695474 T5145 oasc.RequestHandlers.initHandlersFromConfig created /update: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 1695475 T5145 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 1695475 T5145 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 1695475 T5145 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 1695475 T5145 oasc.RequestHandlers.initHandlersFromConfig created /config: org.apache.solr.handler.SolrConfigHandler
   [junit4]   2> 1695476 T5145 oasc.RequestHandlers.initHandlersFromConfig created /schema: org.apache.solr.handler.SchemaHandler
   [junit4]   2> 1695477 T5145 oasc.RequestHandlers.initHandlersFromConfig created /replication: org.apache.solr.handler.ReplicationHandler
   [junit4]   2> 1695477 T5145 oasc.RequestHandlers.initHandlersFromConfig created /get: org.apache.solr.handler.RealTimeGetHandler
   [junit4]   2> 1695478 T5145 oasc.RequestHandlers.initHandlersFromConfig created /admin/luke: org.apache.solr.handler.admin.LukeRequestHandler
   [junit4]   2> 1695478 T5145 oasc.RequestHandlers.initHandlersFromConfig created /admin/system: org.apache.solr.handler.admin.SystemInfoHandler
   [junit4]   2> 1695478 T5145 oasc.RequestHandlers.initHandlersFromConfig created /admin/mbeans: org.apache.solr.handler.admin.SolrInfoMBeanHandler
   [junit4]   2> 1695479 T5145 oasc.RequestHandlers.initHandlersFromConfig created /admin/plugins: org.apache.solr.handler.admin.PluginInfoHandler
   [junit4]   2> 1695479 T5145 oasc.RequestHandlers.initHandlersFromConfig created /admin/threads: org.apache.solr.handler.admin.ThreadDumpHandler
   [junit4]   2> 1695479 T5145 oasc.RequestHandlers.initHandlersFromConfig created /admin/properties: org.apache.solr.handler.admin.PropertiesRequestHandler
   [junit4]   2> 1695480 T5145 oasc.RequestHandlers.initHandlersFromConfig created /admin/logging: org.apache.solr.handler.admin.LoggingHandler
   [junit4]   2> 1695480 T5145 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: org.apache.solr.handler.PingRequestHandler
   [junit4]   2> 1695480 T5145 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1695481 T5145 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1695481 T5145 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 1695483 T5145 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1695484 T5145 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1695485 T5145 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1695486 T5145 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1695487 T5145 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 1695488 T5145 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1695488 T5145 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1695489 T5145 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=31, maxMergeAtOnceExplicit=23, maxMergedSegmentMB=42.5185546875, floorSegmentMB=0.412109375, forceMergeDeletesPctAllowed=5.14195774493436, segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 1695490 T5145 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/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-001/jetty1/index,segFN=segments_1,generation=1}
   [junit4]   2> 1695490 T5145 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1695490 T5145 oass.SolrIndexSearcher.<init> Opening Searcher@3846d997[collection1] main
   [junit4]   2> 1695491 T5145 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1695492 T5145 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1695492 T5145 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 1695493 T5145 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1695493 T5145 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 1695494 T5145 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1695494 T5145 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 1695495 T5145 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1695495 T5145 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 1695495 T5145 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 1695496 T5146 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3846d997[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1695497 T5145 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1695498 T5149 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:59892 collection:collection1 shard:shard2
   [junit4]   2> 1695498 T5088 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 1695499 T5088 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1695499 T5149 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 1695505 T5149 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 1695507 T5114 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1695507 T5149 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1695507 T5149 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C1074 name=collection1 org.apache.solr.core.SolrCore@225a108e url=http://127.0.0.1:59892/collection1 node=127.0.0.1:59892_ C1074_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=http://127.0.0.1:59892, node_name=127.0.0.1:59892_, state=down}
   [junit4]   2> 1695508 T5149 C1074 P59892 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:59892/collection1/
   [junit4]   2> 1695508 T5115 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1"} current state version: 5
   [junit4]   2> 1695508 T5149 C1074 P59892 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1695509 T5149 C1074 P59892 oasc.SyncStrategy.syncToMe http://127.0.0.1:59892/collection1/ has no replicas
   [junit4]   2> 1695509 T5149 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:59892/collection1/ shard2
   [junit4]   2> 1695509 T5149 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 1695510 T5115 oasco.ZkStateWriter.writePendingUpdates going to update_collection /collections/collection1/state.json version: 1
   [junit4]   2> 1695510 T5144 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... 
   [junit4]   2> 1695511 T5144 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 2 
   [junit4]   2> 1695513 T5114 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1695514 T5115 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:59892",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "state":"active"} current state version: 5
   [junit4]   2> 1695515 T5115 oasco.ZkStateWriter.writePendingUpdates going to update_collection /collections/collection1/state.json version: 2
   [junit4]   2> 1695515 T5144 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... 
   [junit4]   2> 1695515 T5144 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 3 
   [junit4]   2> 1695564 T5149 oasc.ZkController.register We are http://127.0.0.1:59892/collection1/ and leader is http://127.0.0.1:59892/collection1/
   [junit4]   2> 1695564 T5149 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:59892
   [junit4]   2> 1695564 T5149 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1695564 T5149 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 1695564 T5149 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1695566 T5114 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1695566 T5115 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:59892",
   [junit4]   2> 	  "node_name":"127.0.0.1:59892_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"} current state version: 5
   [junit4]   2> 1695567 T5115 oasco.ReplicaMutator.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:59892",
   [junit4]   2> 	  "node_name":"127.0.0.1:59892_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 1695568 T5115 oasco.ZkStateWriter.writePendingUpdates going to update_collection /collections/collection1/state.json version: 3
   [junit4]   2> 1695569 T5149 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 3 
   [junit4]   2> 1695569 T5144 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... 
   [junit4]   2> 1695569 T5144 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 4 
   [junit4]   2> 1695738 T5088 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 1695739 T5088 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1695740 T5088 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:40753
   [junit4]   2> 1695742 T5088 oass.SolrDispatchFilter.init SolrDispatchFilter.init()sun.misc.Launcher$AppClassLoader@4e0e2f2a
   [junit4]   2> 1695742 T5088 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1695742 T5088 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-004
   [junit4]   2> 1695743 T5088 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-004/'
   [junit4]   2> 1695752 T5088 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-004/solr.xml
   [junit4]   2> 1695759 T5088 oasc.CoreContainer.<init> New CoreContainer 1880290833
   [junit4]   2> 1695760 T5088 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-004/]
   [junit4]   2> 1695760 T5088 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1695760 T5088 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1695760 T5088 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1695761 T5088 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1695761 T5088 oashc.HttpShardHandlerFactory.getParameter Setting maxConnections to: 10000
   [junit4]   2> 1695761 T5088 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1695761 T5088 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1695762 T5088 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1695762 T5088 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1695762 T5088 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1695762 T5088 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
   [junit4]   2> 1695763 T5088 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1695763 T5088 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1695763 T5088 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1695763 T5088 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:45567/solr
   [junit4]   2> 1695763 T5088 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1695764 T5088 oascc.SolrZkClient.createZkCredentialsToAddAutomatically Using default ZkCredentialsProvider
   [junit4]   2> 1695764 T5088 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1695766 T5161 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7429b92f name:ZooKeeperConnection Watcher:127.0.0.1:45567 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1695768 T5088 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1695768 T5088 oascc.SolrZkClient.createZkACLProvider Using default ZkACLProvider
   [junit4]   2> 1695770 T5088 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1695772 T5164 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5599d13c name:ZooKeeperConnection Watcher:127.0.0.1:45567/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1695772 T5088 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1695778 T5088 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1696784 T5088 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40753_
   [junit4]   2> 1696785 T5088 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40753_
   [junit4]   2> 1696792 T5088 oasc.Overseer.close Overseer (id=null) closing
   [junit4]   2> 1696799 T5165 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 1696800 T5165 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1696802 T5114 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1696803 T5165 oasc.ZkController.preRegister Registering watch for external collection collection1
   [junit4]   2> 1696803 T5165 oascc.ZkStateReader.addZkWatch addZkWatch collection1
   [junit4]   2> 1696804 T5115 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:40753",
   [junit4]   2> 	  "node_name":"127.0.0.1:40753_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"} current state version: 5
   [junit4]   2> 1696804 T5165 oascc.ZkStateReader.addZkWatch Updating collection state at /collections/collection1/state.json from ZooKeeper... 
   [junit4]   2> 1696805 T5115 oasco.ReplicaMutator.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:40753",
   [junit4]   2> 	  "node_name":"127.0.0.1:40753_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"}
   [junit4]   2> 1696805 T5115 oasco.ReplicaMutator.updateState Collection already exists with numShards=2
   [junit4]   2> 1696805 T5115 oasco.ReplicaMutator.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1696806 T5165 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 4 
   [junit4]   2> 1696806 T5165 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1696807 T5115 oasco.ZkStateWriter.writePendingUpdates going to update_collection /collections/collection1/state.json version: 4
   [junit4]   2> 1696807 T5144 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... 
   [junit4]   2> 1696807 T5164 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... 
   [junit4]   2> 1696808 T5144 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 5 
   [junit4]   2> 1696808 T5164 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 5 
   [junit4]   2> 1697806 T5165 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1697807 T5165 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1697808 T5165 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1697808 T5165 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1697809 T5165 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1697809 T5165 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-004/collection1/'
   [junit4]   2> 1697810 T5165 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-004/collection1/lib/.svn/' to classloader
   [junit4]   2> 1697810 T5165 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-004/collection1/lib/classes/' to classloader
   [junit4]   2> 1697811 T5165 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-004/collection1/lib/README' to classloader
   [junit4]   2> 1697825 T5165 oasc.ZkController.watchZKConfDir watch zkdir /configs/conf1
   [junit4]   2> 1697828 T5165 oasc.Config.<init> loaded config solrconfig.xml with version 0 
   [junit4]   2> 1697836 T5165 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.0.0
   [junit4]   2> 1697846 T5165 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1697847 T5165 oass.IndexSchema.readSchema Reading Solr Schema from /configs/conf1/schema.xml
   [junit4]   2> 1697851 T5165 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1697950 T5165 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1697951 T5165 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1697951 T5165 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1697954 T5165 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1697972 T5165 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 1697972 T5165 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 1697972 T5165 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-004/collection1/, dataDir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-001/jetty2/
   [junit4]   2> 1697972 T5165 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7761cb42
   [junit4]   2> 1697973 T5165 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-001/jetty2
   [junit4]   2> 1697973 T5165 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-001/jetty2/index/
   [junit4]   2> 1697973 T5165 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-001/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 1697975 T5165 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-001/jetty2/index
   [junit4]   2> 1697975 T5165 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=50, maxMergeAtOnceExplicit=44, maxMergedSegmentMB=37.7763671875, floorSegmentMB=2.0107421875, forceMergeDeletesPctAllowed=22.637801835175402, segmentsPerTier=46.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.7411699806539382
   [junit4]   2> 1697983 T5165 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/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-001/jetty2/index,segFN=segments_1,generation=1}
   [junit4]   2> 1697984 T5165 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1697988 T5165 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1697988 T5165 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1697989 T5165 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1697989 T5165 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1697989 T5165 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1697990 T5165 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1697990 T5165 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1697990 T5165 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1697991 T5165 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1697991 T5165 oasc.RequestHandlers.initHandlersFromConfig created /update: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 1697992 T5165 oasc.RequestHandlers.initHandlersFromConfig created /update/json: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 1697992 T5165 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 1697993 T5165 oasc.RequestHandlers.initHandlersFromConfig created /update/json/docs: org.apache.solr.handler.UpdateRequestHandler
   [junit4]   2> 1697993 T5165 oasc.RequestHandlers.initHandlersFromConfig created /config: org.apache.solr.handler.SolrConfigHandler
   [junit4]   2> 1697994 T5165 oasc.RequestHandlers.initHandlersFromConfig created /schema: org.apache.solr.handler.SchemaHandler
   [junit4]   2> 1697996 T5165 oasc.RequestHandlers.initHandlersFromConfig created /replication: org.apache.solr.handler.ReplicationHandler
   [junit4]   2> 1697997 T5165 oasc.RequestHandlers.initHandlersFromConfig created /get: org.apache.solr.handler.RealTimeGetHandler
   [junit4]   2> 1697997 T5165 oasc.RequestHandlers.initHandlersFromConfig created /admin/luke: org.apache.solr.handler.admin.LukeRequestHandler
   [junit4]   2> 1697998 T5165 oasc.RequestHandlers.initHandlersFromConfig created /admin/system: org.apache.solr.handler.admin.SystemInfoHandler
   [junit4]   2> 1697999 T5165 oasc.RequestHandlers.initHandlersFromConfig created /admin/mbeans: org.apache.solr.handler.admin.SolrInfoMBeanHandler
   [junit4]   2> 1697999 T5165 oasc.RequestHandlers.initHandlersFromConfig created /admin/plugins: org.apache.solr.handler.admin.PluginInfoHandler
   [junit4]   2> 1698000 T5165 oasc.RequestHandlers.initHandlersFromConfig created /admin/threads: org.apache.solr.handler.admin.ThreadDumpHandler
   [junit4]   2> 1698000 T5165 oasc.RequestHandlers.initHandlersFromConfig created /admin/properties: org.apache.solr.handler.admin.PropertiesRequestHandler
   [junit4]   2> 1698001 T5165 oasc.RequestHandlers.initHandlersFromConfig created /admin/logging: org.apache.solr.handler.admin.LoggingHandler
   [junit4]   2> 1698001 T5165 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: org.apache.solr.handler.PingRequestHandler
   [junit4]   2> 1698002 T5165 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1698002 T5165 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1698002 T5165 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 1698004 T5165 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1698004 T5165 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1698005 T5165 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1698006 T5165 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1698006 T5165 oasc.SolrCore.initStatsCache Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
   [junit4]   2> 1698007 T5165 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1698007 T5165 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1698007 T5165 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=31, maxMergeAtOnceExplicit=23, maxMergedSegmentMB=42.5185546875, floorSegmentMB=0.412109375, forceMergeDeletesPctAllowed=5.14195774493436, segmentsPerTier=40.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 1698008 T5165 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/temp/solr.cloud.ChaosMonkeySafeLeaderTest-78D62EC33B461E33-001/tempDir-001/jetty2/index,segFN=segments_1,generation=1}
   [junit4]   2> 1698008 T5165 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1698008 T5165 oass.SolrIndexSearcher.<init> Opening Searcher@2b95bec[collection1] main
   [junit4]   2> 1698009 T5165 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1698010 T5165 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1698011 T5165 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 1698011 T5165 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1698012 T5165 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 1698012 T5165 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1698013 T5165 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 1698013 T5165 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1698013 T5165 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 1698014 T5165 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 1698015 T5165 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1698015 T5166 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2b95bec[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1698016 T5169 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:40753 collection:collection1 shard:shard1
   [junit4]   2> 1698016 T5088 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 1698017 T5088 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1698017 T5169 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 1698021 T5169 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1698022 T5114 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1698022 T5169 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1698022 T5169 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 1698022 T5115 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1"} current state version: 5
   [junit4]   2> ASYNC  NEW_CORE C1075 name=collection1 org.apache.solr.core.SolrCore@364e3f4a url=http://127.0.0.1:40753/collection1 node=127.0.0.1:40753_ C1075_STATE=coll:collection1 core:collection1 props:{core=collection1, base_url=http://127.0.0.1:40753, node_name=127.0.0.1:40753_, state=down}
   [junit4]   2> 1698022 T5169 C1075 P40753 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:40753/collection1/
   [junit4]   2> 1698022 T5169 C1075 P40753 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1698023 T5169 C1075 P40753 oasc.SyncStrategy.syncToMe http://127.0.0.1:40753/collection1/ has no replicas
   [junit4]   2> 1698023 T5115 oasco.ZkStateWriter.writePendingUpdates going to update_collection /collections/collection1/state.json version: 5
   [junit4]   2> 1698023 T5169 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:40753/collection1/ shard1
   [junit4]   2> 1698023 T5169 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 1698023 T5164 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... 
   [junit4]   2> 1698023 T5144 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... 
   [junit4]   2> 1698024 T5164 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 6 
   [junit4]   2> 1698024 T5144 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 6 
   [junit4]   2> 1698025 T5114 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1698025 T5115 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "operation":"leader",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:40753",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "state":"active"} current state version: 5
   [junit4]   2> 1698026 T5115 oasco.ZkStateWriter.writePendingUpdates going to update_collection /collections/collection1/state.json version: 6
   [junit4]   2> 1698026 T5164 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... 
   [junit4]   2> 1698026 T5144 oascc.ZkStateReader$7.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json, has occurred - updating... 
   [junit4]   2> 1698027 T5164 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 7 
   [junit4]   2> 1698027 T5144 oascc.ZkStateReader.updateWatchedCollection Updating data for collection1 to ver 7 
   [junit4]   2> 1698075 T5169 oasc.ZkController.register We are http://127.0.0.1:40753/collection1/ and leader is http://127.0.0.1:40753/collection1/
   [junit4]   2> 1698076 T5169 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:40753
   [junit4]   2> 1698076 T5169 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1698076 T5169 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 1698076 T5169 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1698077 T5114 oasc.DistributedQueue$LatchWatcher.process NodeChildrenChanged fired on path /overseer/queue state SyncConnected
   [junit4]   2> 1698078 T5115 oasc.Overseer$ClusterStateUpdater.run processMessage: queueSize: 1, message = {
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:40753",
   [junit4]   2> 	  "node_name":"127.0.0.1:40753_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "operation":"state"} current state version: 5
   [junit4]   2> 1698078 T5115 oasco.ReplicaMutator.updateState Update state numShards=2 message={
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "core_node_name":"core_node2",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "base_url":"http://127.0.0.1:40753",
   [junit4]   2> 	  "node_name":"127.0.0.1:40753_",
   [junit4]   2> 	  "numShards":"2",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "shard":"shard1",
   [ju

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

$TransferStack.awaitFulfill(SynchronousQueue.java:460)
   [junit4]   2> 	        at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
   [junit4]   2> 	        at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 	  30) Thread[id=5134, name=qtp1105875591-5134 Acceptor1 SelectChannelConnector@127.0.0.1:59892, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:956)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 	  31) Thread[id=5167, name=Thread-2038, state=WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at java.lang.Object.wait(Native Method)
   [junit4]   2> 	        at java.lang.Object.wait(Object.java:502)
   [junit4]   2> 	        at org.apache.solr.core.CloserThread.run(CoreContainer.java:929)
   [junit4]   2> 	  32) Thread[id=5152, name=qtp735740999-5152 Selector1, 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:86)
   [junit4]   2> 	        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
   [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:745)
   [junit4]   2> 	  33) Thread[id=5196, name=commitScheduler-2638-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:175)
   [junit4]   2> 	        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
   [junit4]   2> 	        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1081)
   [junit4]   2> 	        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 	  34) Thread[id=5809, name=zkCallback-692-thread-115, state=TIMED_WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at sun.misc.Unsafe.park(Native Method)
   [junit4]   2> 	        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
   [junit4]   2> 	        at java.util.concurrent.SynchronousQueue$TransferStack.awaitFulfill(SynchronousQueue.java:460)
   [junit4]   2> 	        at java.util.concurrent.SynchronousQueue$TransferStack.transfer(SynchronousQueue.java:362)
   [junit4]   2> 	        at java.util.concurrent.SynchronousQueue.poll(SynchronousQueue.java:941)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1066)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> NOTE: test params are: codec=DummyCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=DUMMY, chunkSize=10045, maxDocsPerChunk=815), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=DUMMY, chunkSize=10045)), sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=iw_IL, timezone=Asia/Hong_Kong
   [junit4]   2> NOTE: Linux 3.13.0-43-generic amd64/Oracle Corporation 1.9.0-ea (64-bit)/cpus=8,threads=40,free=191353176,total=536870912
   [junit4]   2> NOTE: All tests run in this JVM: [TestExceedMaxTermLength, URLClassifyProcessorTest, FacetPivotSmallTest, HdfsCollectionsAPIDistributedZkTest, TestSolrConfigHandlerCloud, SpellPossibilityIteratorTest, TestSolrDeletionPolicy1, TriLevelCompositeIdRoutingTest, RollingRestartTest, TestPHPSerializedResponseWriter, TestNonDefinedSimilarityFactory, OverriddenZkACLAndCredentialsProvidersTest, JsonLoaderTest, TestCollationFieldDocValues, TestLFUCache, DocumentBuilderTest, SignatureUpdateProcessorFactoryTest, SpellCheckCollatorTest, TestRTGBase, UpdateParamsTest, IndexBasedSpellCheckerTest, TestCharFilters, CopyFieldTest, ExternalCollectionsTest, TestFieldResource, TestReplicationHandlerBackup, TestFiltering, DistributedQueryComponentCustomSortTest, TestDefaultSearchFieldResource, TestPostingsSolrHighlighter, SchemaVersionSpecificBehaviorTest, ExternalFileFieldSortTest, BadCopyFieldTest, TestInitQParser, TestSolrJ, IndexSchemaTest, CollectionsAPIDistributedZkTest, TestSortingResponseWriter, TestFreeTextSuggestions, QueryEqualityTest, ResponseLogComponentTest, PrimitiveFieldTypeTest, CSVRequestHandlerTest, DebugComponentTest, TermVectorComponentDistributedTest, SolrCmdDistributorTest, SampleTest, FileUtilsTest, ScriptEngineTest, TestDefaultStatsCache, TestRawResponseWriter, TestJoin, ConnectionManagerTest, ShardSplitTest, ModifyConfFileTest, TestZkChroot, TestStandardQParsers, AsyncMigrateRouteKeyTest, TestConfig, TestJmxMonitoredMap, WordBreakSolrSpellCheckerTest, RegexBoostProcessorTest, FullSolrCloudDistribCmdsTest, TestFieldTypeResource, TestFastLRUCache, QueryResultKeyTest, ShardRoutingCustomTest, TestMissingGroups, AliasIntegrationTest, TestExactStatsCache, UUIDUpdateProcessorFallbackTest, TestDynamicLoading, BasicDistributedZk2Test, TestIntervalFaceting, AnalyticsMergeStrategyTest, HdfsUnloadDistributedZkTest, DateRangeFieldTest, DisMaxRequestHandlerTest, BadComponentTest, ChaosMonkeyNothingIsSafeTest, TestTolerantSearch, LeaderElectionIntegrationTest, TestDefaultSimilarityFactory, ConvertedLegacyTest, TestDocSet, TestRecovery, UpdateRequestProcessorFactoryTest, SimplePostToolTest, HdfsDirectoryTest, SolrRequestParserTest, StatsComponentTest, FastVectorHighlighterTest, TestSuggestSpellingConverter, TestSerializedLuceneMatchVersion, TestRandomMergePolicy, TestAnalyzeInfixSuggestions, TestRealTimeGet, TestAddFieldRealTimeGet, TestDynamicFieldResource, DocValuesMissingTest, HdfsChaosMonkeySafeLeaderTest, SpatialFilterTest, CurrencyFieldXmlFileTest, TestImplicitCoreProperties, TestCollectionAPI, TestLMJelinekMercerSimilarityFactory, TestSchemaManager, TestSchemaSimilarityResource, TestManagedSchemaFieldResource, TestTrie, ChaosMonkeySafeLeaderTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=ChaosMonkeySafeLeaderTest -Dtests.seed=78D62EC33B461E33 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=iw_IL -Dtests.timezone=Asia/Hong_Kong -Dtests.asserts=true -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([78D62EC33B461E33]:0)
   [junit4] Completed on J1 in 7224.07s, 1 test, 2 errors <<< FAILURES!

[...truncated 11 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:519: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:61: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:187: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:510: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1349: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:956: There were test failures: 459 suites, 1856 tests, 1 suite-level error, 1 error, 32 ignored (22 assumptions)

Total time: 173 minutes 54 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 64bit/jdk1.9.0-ea-b34 -XX:-UseCompressedOops -XX:+UseG1GC (asserts: true)
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any



Mime
View raw message