You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/05/20 01:18:49 UTC

[JENKINS] Lucene-Solr-trunk-Linux (64bit/jdk1.8.0_05) - Build # 10337 - Still Failing!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/10337/
Java: 64bit/jdk1.8.0_05 -XX:+UseCompressedOops -XX:+UseSerialGC

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


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

Error Message:
Test abandoned because suite timeout was reached.

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




Build Log:
[...truncated 11579 lines...]
   [junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/init-core-data-001
   [junit4]   2> 5861 T45 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (true)
   [junit4]   2> 5862 T45 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /iudwc/
   [junit4]   2> 5872 T45 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> 5882 T45 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 5887 T46 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 5985 T45 oasc.ZkTestServer.run start zk server on port:46791
   [junit4]   2> 6061 T45 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 6092 T47 oazs.NIOServerCnxn.doIO WARN Exception causing close of session 0x0 due to java.io.IOException: ZooKeeperServer not running
   [junit4]   2> 8311 T52 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@12eb7b63 name:ZooKeeperConnection Watcher:127.0.0.1:46791 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 8312 T45 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 8315 T45 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 8345 T45 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 8351 T54 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@766f53e5 name:ZooKeeperConnection Watcher:127.0.0.1:46791/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 8351 T45 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 8362 T45 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 8378 T45 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 8384 T45 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 8390 T45 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 8397 T45 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> 8409 T45 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 8429 T45 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> 8430 T45 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 8434 T45 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> 8435 T45 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 8440 T45 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> 8440 T45 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 8447 T45 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> 8448 T45 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 8453 T45 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> 8455 T45 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 8460 T45 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> 8461 T45 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 8467 T45 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> 8468 T45 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 8473 T45 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> 8474 T45 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 8479 T45 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> 8480 T45 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 8484 T45 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> 8485 T45 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 8503 T45 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 8512 T56 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@649ef4bb name:ZooKeeperConnection Watcher:127.0.0.1:46791/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 8513 T45 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 9174 T45 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 9552 T45 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 9611 T45 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:49720
   [junit4]   2> 9646 T45 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 9646 T45 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 9647 T45 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-002
   [junit4]   2> 9647 T45 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-002/'
   [junit4]   2> 9686 T45 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-002/solr.xml
   [junit4]   2> 9749 T45 oasc.CoreContainer.<init> New CoreContainer 562968542
   [junit4]   2> 9750 T45 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-002/]
   [junit4]   2> 9763 T45 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 9763 T45 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 9764 T45 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 9764 T45 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 9765 T45 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 9765 T45 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 9766 T45 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 9766 T45 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 9767 T45 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 9771 T45 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 9771 T45 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 9772 T45 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 9772 T45 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:46791/solr
   [junit4]   2> 9787 T45 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 9809 T45 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 9815 T68 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@40cd9149 name:ZooKeeperConnection Watcher:127.0.0.1:46791 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 9815 T45 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 9844 T45 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 9847 T70 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2ba0ae0c name:ZooKeeperConnection Watcher:127.0.0.1:46791/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 9848 T45 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 9859 T45 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 9881 T45 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 9891 T45 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 9901 T45 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 9905 T45 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 9928 T45 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 9936 T45 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49720_iudwc
   [junit4]   2> 9950 T45 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49720_iudwc
   [junit4]   2> 9963 T45 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 9966 T45 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 9981 T45 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:49720_iudwc
   [junit4]   2> 9982 T45 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 9986 T45 oasc.Overseer.start Overseer (id=91785414119260164-127.0.0.1:49720_iudwc-n_0000000000) starting
   [junit4]   2> 10001 T45 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 10054 T72 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 10066 T71 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 10070 T45 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 10078 T45 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 10080 T45 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 10093 T73 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 10094 T73 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 10098 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 10098 T73 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 10100 T71 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 10103 T71 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:49720/iudwc",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49720_iudwc",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 10104 T71 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 10113 T71 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 10117 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 10125 T70 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> 11099 T73 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 11099 T73 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 11100 T73 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 11100 T73 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 11101 T73 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 11102 T73 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-002/collection1/'
   [junit4]   2> 11103 T73 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-002/collection1/lib/.svn/' to classloader
   [junit4]   2> 11103 T73 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-002/collection1/lib/classes/' to classloader
   [junit4]   2> 11104 T73 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-002/collection1/lib/README' to classloader
   [junit4]   2> 11145 T73 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
   [junit4]   2> 11162 T73 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 11163 T73 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 11215 T73 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 11504 T73 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 11505 T73 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 11507 T73 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 11513 T73 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 11637 T73 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 11638 T73 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 11649 T73 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-002/collection1/, dataDir=./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/control/data/
   [junit4]   2> 11653 T73 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6bc238c6
   [junit4]   2> 11682 T73 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/control/data
   [junit4]   2> 11683 T73 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/control/data/index/
   [junit4]   2> 11683 T73 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 11684 T73 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/control/data/index
   [junit4]   2> 11684 T73 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=34, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4383069373349874]
   [junit4]   2> 11690 T73 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/control/data/index,segFN=segments_1,generation=1}
   [junit4]   2> 11690 T73 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 11700 T73 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 11734 T73 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 11738 T73 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 11738 T73 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 11739 T73 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 11739 T73 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 11777 T73 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 11778 T73 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 11778 T73 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 11780 T73 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 11788 T73 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 11789 T73 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 11791 T73 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 11792 T73 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 11793 T73 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 11800 T73 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 11810 T73 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 11813 T73 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 11824 T73 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 11825 T73 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 11827 T73 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=50, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.46371057483233924]
   [junit4]   2> 11829 T73 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/control/data/index,segFN=segments_1,generation=1}
   [junit4]   2> 11829 T73 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 11830 T73 oass.SolrIndexSearcher.<init> Opening Searcher@6a3268bb[collection1] main
   [junit4]   2> 11830 T73 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 11832 T73 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 11833 T73 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 11837 T73 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 11837 T73 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 11838 T73 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 11839 T73 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 11840 T73 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 11840 T73 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 11842 T73 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 11864 T74 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6a3268bb[collection1] main{UninvertingDirectoryReader()}
   [junit4]   2> 11872 T73 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 11878 T77 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:49720/iudwc collection:control_collection shard:shard1
   [junit4]   2> 11879 T45 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 11880 T45 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 11888 T77 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 11913 T77 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 11919 T45 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 11940 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 11942 T77 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 11942 T77 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C2 name=collection1 org.apache.solr.core.SolrCore@5f352f3c url=https://127.0.0.1:49720/iudwc/collection1 node=127.0.0.1:49720_iudwc C2_STATE=coll:control_collection core:collection1 props:{state=down, base_url=https://127.0.0.1:49720/iudwc, core=collection1, node_name=127.0.0.1:49720_iudwc}
   [junit4]   2> 11944 T77 C2 P49720 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:49720/iudwc/collection1/
   [junit4]   2> 11945 T77 C2 P49720 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 11945 T77 C2 P49720 oasc.SyncStrategy.syncToMe https://127.0.0.1:49720/iudwc/collection1/ has no replicas
   [junit4]   2> 11945 T77 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:49720/iudwc/collection1/ shard1
   [junit4]   2> 11947 T71 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 11948 T77 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 11950 T79 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4892e14 name:ZooKeeperConnection Watcher:127.0.0.1:46791/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 11951 T45 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 11954 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 11955 T45 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 11956 T70 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> 11960 T45 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 11987 T71 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 11997 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 12100 T79 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> 12101 T70 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> 12137 T77 oasc.ZkController.register We are https://127.0.0.1:49720/iudwc/collection1/ and leader is https://127.0.0.1:49720/iudwc/collection1/
   [junit4]   2> 12139 T77 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:49720/iudwc
   [junit4]   2> 12139 T77 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 12140 T77 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 12140 T77 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 12148 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 12148 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 12149 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 12149 T77 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 12158 T71 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 12160 T71 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:49720/iudwc",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49720_iudwc",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 12166 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 12269 T70 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> 12269 T79 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> 12535 T45 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 12539 T45 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 12550 T45 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 12554 T45 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:53035
   [junit4]   2> 12562 T45 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 12562 T45 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 12563 T45 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-003
   [junit4]   2> 12563 T45 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-003/'
   [junit4]   2> 12584 T45 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-003/solr.xml
   [junit4]   2> 12602 T45 oasc.CoreContainer.<init> New CoreContainer 1592501163
   [junit4]   2> 12603 T45 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-003/]
   [junit4]   2> 12604 T45 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 12604 T45 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 12605 T45 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 12605 T45 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 12606 T45 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 12607 T45 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 12608 T45 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 12608 T45 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 12609 T45 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 12621 T45 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 12622 T45 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 12623 T45 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 12624 T45 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:46791/solr
   [junit4]   2> 12624 T45 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 12633 T45 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 12639 T90 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@63834304 name:ZooKeeperConnection Watcher:127.0.0.1:46791 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 12640 T45 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 12650 T45 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 12655 T92 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2908deb5 name:ZooKeeperConnection Watcher:127.0.0.1:46791/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 12659 T45 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 12671 T45 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 13675 T45 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53035_iudwc
   [junit4]   2> 13676 T45 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53035_iudwc
   [junit4]   2> 13688 T93 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 13688 T93 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 13690 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 13690 T93 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 13690 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 13691 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 13692 T71 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 13693 T71 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:53035/iudwc",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53035_iudwc",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 13694 T71 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
   [junit4]   2> 13694 T71 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 13698 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 13906 T79 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 13906 T92 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 13906 T70 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 14691 T93 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 14691 T93 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 14692 T93 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 14692 T93 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 14693 T93 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 14693 T93 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-003/collection1/'
   [junit4]   2> 14694 T93 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-003/collection1/lib/.svn/' to classloader
   [junit4]   2> 14694 T93 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-003/collection1/lib/classes/' to classloader
   [junit4]   2> 14695 T93 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-003/collection1/lib/README' to classloader
   [junit4]   2> 14729 T93 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
   [junit4]   2> 14755 T93 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 14756 T93 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 14786 T93 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 14921 T93 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 14922 T93 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 14923 T93 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 14927 T93 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 14958 T93 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 14958 T93 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 14958 T93 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-003/collection1/, dataDir=./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/jetty1/
   [junit4]   2> 14959 T93 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6bc238c6
   [junit4]   2> 14961 T93 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/jetty1
   [junit4]   2> 14961 T93 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/jetty1/index/
   [junit4]   2> 14961 T93 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 14962 T93 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/jetty1/index
   [junit4]   2> 14962 T93 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=34, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4383069373349874]
   [junit4]   2> 14968 T93 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/jetty1/index,segFN=segments_1,generation=1}
   [junit4]   2> 14968 T93 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 14975 T93 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 14976 T93 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 14976 T93 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 14977 T93 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 14977 T93 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 14977 T93 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 14977 T93 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 14978 T93 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 14978 T93 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 14979 T93 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 14979 T93 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 14979 T93 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 14980 T93 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 14981 T93 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 14981 T93 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 14982 T93 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 14982 T93 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 14984 T93 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 14985 T93 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 14986 T93 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 14987 T93 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=50, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.46371057483233924]
   [junit4]   2> 14988 T93 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/jetty1/index,segFN=segments_1,generation=1}
   [junit4]   2> 14988 T93 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 14989 T93 oass.SolrIndexSearcher.<init> Opening Searcher@505f31af[collection1] main
   [junit4]   2> 14989 T93 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 14990 T93 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 14990 T93 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 14991 T93 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 14991 T93 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 14991 T93 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 14992 T93 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 14992 T93 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 14992 T93 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 14993 T93 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 14998 T94 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@505f31af[collection1] main{UninvertingDirectoryReader()}
   [junit4]   2> 15002 T93 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 15003 T97 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:53035/iudwc collection:collection1 shard:shard2
   [junit4]   2> 15003 T45 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 15004 T45 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 15011 T97 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 15020 T97 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 15022 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 15023 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 15023 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 15024 T97 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 15025 T71 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 15025 T97 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C3 name=collection1 org.apache.solr.core.SolrCore@442c7c0 url=https://127.0.0.1:53035/iudwc/collection1 node=127.0.0.1:53035_iudwc C3_STATE=coll:collection1 core:collection1 props:{state=down, base_url=https://127.0.0.1:53035/iudwc, core=collection1, node_name=127.0.0.1:53035_iudwc}
   [junit4]   2> 15027 T97 C3 P53035 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:53035/iudwc/collection1/
   [junit4]   2> 15028 T97 C3 P53035 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 15028 T97 C3 P53035 oasc.SyncStrategy.syncToMe https://127.0.0.1:53035/iudwc/collection1/ has no replicas
   [junit4]   2> 15028 T97 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:53035/iudwc/collection1/ shard2
   [junit4]   2> 15029 T97 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 15030 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 15045 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 15049 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 15151 T70 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 15151 T92 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 15151 T79 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 15197 T97 oasc.ZkController.register We are https://127.0.0.1:53035/iudwc/collection1/ and leader is https://127.0.0.1:53035/iudwc/collection1/
   [junit4]   2> 15197 T97 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:53035/iudwc
   [junit4]   2> 15197 T97 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 15198 T97 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 15198 T97 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 15202 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 15202 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 15203 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 15203 T97 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 15204 T71 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 15206 T71 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:53035/iudwc",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:53035_iudwc",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 15209 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 15303 T45 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 15304 T45 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 15309 T45 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 15312 T45 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:60111
   [junit4]   2> 15313 T79 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 15313 T70 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 15313 T92 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 15318 T45 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 15318 T45 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 15318 T45 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-004
   [junit4]   2> 15319 T45 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-004/'
   [junit4]   2> 15330 T45 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-004/solr.xml
   [junit4]   2> 15353 T45 oasc.CoreContainer.<init> New CoreContainer 89633028
   [junit4]   2> 15354 T45 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-004/]
   [junit4]   2> 15355 T45 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 15355 T45 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 15356 T45 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 15356 T45 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 15356 T45 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 15357 T45 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 15357 T45 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 15358 T45 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 15358 T45 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 15362 T45 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 15363 T45 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 15363 T45 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 15364 T45 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:46791/solr
   [junit4]   2> 15364 T45 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 15365 T45 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 15368 T108 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2f87e61 name:ZooKeeperConnection Watcher:127.0.0.1:46791 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 15369 T45 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 15376 T45 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 15383 T110 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@40ebcc5b name:ZooKeeperConnection Watcher:127.0.0.1:46791/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 15383 T45 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 15391 T45 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 16394 T45 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60111_iudwc
   [junit4]   2> 16396 T45 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:60111_iudwc
   [junit4]   2> 16406 T111 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 16407 T111 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 16408 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 16408 T111 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 16408 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 16409 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 16409 T71 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 16410 T71 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:60111/iudwc",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:60111_iudwc",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 16411 T71 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 16411 T71 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 16413 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 16518 T70 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 16519 T79 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 16518 T92 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 16518 T110 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 17409 T111 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 17409 T111 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 17410 T111 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 17410 T111 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 17412 T111 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 17413 T111 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-004/collection1/'
   [junit4]   2> 17413 T111 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-004/collection1/lib/.svn/' to classloader
   [junit4]   2> 17414 T111 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-004/collection1/lib/classes/' to classloader
   [junit4]   2> 17415 T111 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-004/collection1/lib/README' to classloader
   [junit4]   2> 17470 T111 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
   [junit4]   2> 17481 T111 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 17483 T111 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 17505 T111 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 17655 T111 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 17665 T111 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 17666 T111 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 17672 T111 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 17706 T111 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 17706 T111 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 17706 T111 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-004/collection1/, dataDir=./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/jetty2/
   [junit4]   2> 17707 T111 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6bc238c6
   [junit4]   2> 17708 T111 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/jetty2
   [junit4]   2> 17708 T111 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/jetty2/index/
   [junit4]   2> 17708 T111 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 17709 T111 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/jetty2/index
   [junit4]   2> 17710 T111 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=34, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4383069373349874]
   [junit4]   2> 17716 T111 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/jetty2/index,segFN=segments_1,generation=1}
   [junit4]   2> 17716 T111 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 17724 T111 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 17724 T111 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 17724 T111 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 17725 T111 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 17725 T111 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 17725 T111 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 17726 T111 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 17726 T111 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 17726 T111 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 17727 T111 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 17728 T111 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 17728 T111 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 17728 T111 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 17729 T111 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 17729 T111 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 17730 T111 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 17730 T111 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 17732 T111 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 17733 T111 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 17734 T111 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 17735 T111 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=50, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.46371057483233924]
   [junit4]   2> 17737 T111 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/jetty2/index,segFN=segments_1,generation=1}
   [junit4]   2> 17737 T111 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 17737 T111 oass.SolrIndexSearcher.<init> Opening Searcher@73c55cfc[collection1] main
   [junit4]   2> 17737 T111 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 17739 T111 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 17739 T111 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 17739 T111 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 17739 T111 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 17740 T111 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 17740 T111 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 17740 T111 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 17741 T111 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 17741 T111 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 17746 T112 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@73c55cfc[collection1] main{UninvertingDirectoryReader()}
   [junit4]   2> 17750 T111 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 17751 T115 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:60111/iudwc collection:collection1 shard:shard3
   [junit4]   2> 17751 T45 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 17752 T115 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 17752 T45 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 17758 T115 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard3
   [junit4]   2> 17760 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 17760 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 17760 T115 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 17760 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 17761 T115 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C4 name=collection1 org.apache.solr.core.SolrCore@25242add url=https://127.0.0.1:60111/iudwc/collection1 node=127.0.0.1:60111_iudwc C4_STATE=coll:collection1 core:collection1 props:{state=down, base_url=https://127.0.0.1:60111/iudwc, core=collection1, node_name=127.0.0.1:60111_iudwc}
   [junit4]   2> 17761 T115 C4 P60111 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:60111/iudwc/collection1/
   [junit4]   2> 17761 T115 C4 P60111 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 17761 T115 C4 P60111 oasc.SyncStrategy.syncToMe https://127.0.0.1:60111/iudwc/collection1/ has no replicas
   [junit4]   2> 17762 T115 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:60111/iudwc/collection1/ shard3
   [junit4]   2> 17762 T115 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
   [junit4]   2> 17762 T71 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 17766 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 17770 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 17773 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 17877 T110 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 17877 T79 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 17877 T70 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 17877 T92 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 17921 T115 oasc.ZkController.register We are https://127.0.0.1:60111/iudwc/collection1/ and leader is https://127.0.0.1:60111/iudwc/collection1/
   [junit4]   2> 17921 T115 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:60111/iudwc
   [junit4]   2> 17921 T115 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 17921 T115 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 17922 T115 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 17923 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 17924 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 17924 T115 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 17924 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 17925 T71 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 17926 T71 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:60111/iudwc",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:60111_iudwc",
   [junit4]   2> 	  "shard":"shard3",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 17928 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 18009 T45 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
   [junit4]   2> 18010 T45 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 18014 T45 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 18016 T45 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:55861
   [junit4]   2> 18019 T45 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 18019 T45 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 18019 T45 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-005
   [junit4]   2> 18020 T45 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-005/'
   [junit4]   2> 18031 T110 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 18031 T92 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 18031 T79 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 18031 T70 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 18032 T45 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-005/solr.xml
   [junit4]   2> 18051 T45 oasc.CoreContainer.<init> New CoreContainer 384201695
   [junit4]   2> 18051 T45 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-005/]
   [junit4]   2> 18052 T45 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 18052 T45 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 18053 T45 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 18053 T45 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 18054 T45 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 18054 T45 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 18054 T45 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 18055 T45 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 18055 T45 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 18059 T45 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 18059 T45 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 18059 T45 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 18060 T45 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:46791/solr
   [junit4]   2> 18060 T45 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 18061 T45 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 18064 T126 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@36114a2d name:ZooKeeperConnection Watcher:127.0.0.1:46791 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 18064 T45 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 18067 T45 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 18069 T128 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4ad80b63 name:ZooKeeperConnection Watcher:127.0.0.1:46791/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 18069 T45 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 18075 T45 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 19079 T45 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55861_iudwc
   [junit4]   2> 19081 T45 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55861_iudwc
   [junit4]   2> 19088 T129 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 19089 T129 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 19090 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 19090 T129 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 19090 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 19091 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 19093 T71 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 19094 T71 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:55861/iudwc",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:55861_iudwc",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 19094 T71 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 19094 T71 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 19102 T70 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 19205 T70 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 19205 T79 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 19205 T92 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 19205 T128 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 19205 T110 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 20091 T129 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 20091 T129 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 20092 T129 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 20092 T129 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 20093 T129 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 20093 T129 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-005/collection1/'
   [junit4]   2> 20094 T129 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-005/collection1/lib/.svn/' to classloader
   [junit4]   2> 20094 T129 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-005/collection1/lib/classes/' to classloader
   [junit4]   2> 20095 T129 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-005/collection1/lib/README' to classloader
   [junit4]   2> 20134 T129 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
   [junit4]   2> 20150 T129 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 20151 T129 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 20167 T129 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 20300 T129 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 20301 T129 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 20302 T129 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 20305 T129 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 20335 T129 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 20335 T129 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 20336 T129 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-005/collection1/, dataDir=./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/jetty3/
   [junit4]   2> 20336 T129 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@6bc238c6
   [junit4]   2> 20337 T129 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/jetty3
   [junit4]   2> 20337 T129 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/jetty3/index/
   [junit4]   2> 20337 T129 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 20338 T129 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/jetty3/index
   [junit4]   2> 20339 T129 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=34, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4383069373349874]
   [junit4]   2> 20347 T129 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-B233B917661C5A5-001/tempDir-001/jetty3/index,segFN=segments_1,generation=1}
   [junit4]   2> 20347 T129 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 20354 T129 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 20354 T129 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 20355 T129 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 20355 T129 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 20355 T129 oasup.UpdateRequestProcessorChain.init inserting DistributedUpd

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

g.Thread.run(Thread.java:745)
   [junit4]   2> 	  77) Thread[id=1191, name=Thread-620, 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:944)
   [junit4]   2> 	  78) Thread[id=1176, name=qtp1007306727-1176 Selector0, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
   [junit4]   2> 	        at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
   [junit4]   2> 	        at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
   [junit4]   2> 	        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
   [junit4]   2> 	        at sun.nio.ch.SelectorImpl.selectNow(SelectorImpl.java:105)
   [junit4]   2> 	        at org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:536)
   [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> 	  79) Thread[id=1208, name=Thread-158-SendThread(127.0.0.1:46791), state=TIMED_WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at java.lang.Thread.sleep(Native Method)
   [junit4]   2> 	        at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:101)
   [junit4]   2> 	        at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:940)
   [junit4]   2> 	        at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1003)
   [junit4]   2> 	  80) Thread[id=993, name=qtp1613046640-993 Acceptor1 SslSelectChannelConnector@127.0.0.1:36560, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:938)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 	  81) Thread[id=1177, name=qtp1007306727-1177 Selector1, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at sun.nio.ch.IOUtil.drain(Native Method)
   [junit4]   2> 	        at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:90)
   [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> 	  82) Thread[id=130, name=searcherExecutor-43-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.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
   [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> 	  83) Thread[id=1198, name=qtp1425180379-1198 Selector0, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
   [junit4]   2> 	        at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
   [junit4]   2> 	        at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
   [junit4]   2> 	        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java: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> 	  84) Thread[id=1169, name=searcherExecutor-424-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.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
   [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> 7232179 T978 oaz.ClientCnxn$SendThread.run WARN Session 0x14616590c240057 for server null, unexpected error, closing socket connection and attempting reconnect java.net.ConnectException: Connection refused
   [junit4]   2> 	at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
   [junit4]   2> 	at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:712)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1081)
   [junit4]   2> 
   [junit4]   2> 7232207 T584 oaz.ClientCnxn$SendThread.run WARN Session 0x14616590c240033 for server null, unexpected error, closing socket connection and attempting reconnect java.net.ConnectException: Connection refused
   [junit4]   2> 	at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
   [junit4]   2> 	at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:712)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1081)
   [junit4]   2> 
   [junit4]   2> NOTE: test params are: codec=CheapBastard, sim=DefaultSimilarity, locale=ar_IQ, timezone=America/Guayaquil
   [junit4]   2> NOTE: Linux 3.8.0-39-generic amd64/Oracle Corporation 1.8.0_05 (64-bit)/cpus=8,threads=98,free=154558344,total=518979584
   [junit4]   2> NOTE: All tests run in this JVM: [TestLMDirichletSimilarityFactory, TestStressLucene, OutputWriterTest, ChaosMonkeySafeLeaderTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=ChaosMonkeySafeLeaderTest -Dtests.seed=B233B917661C5A5 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ar_IQ -Dtests.timezone=America/Guayaquil -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([B233B917661C5A5]:0)
   [junit4] Completed on J1 in 7226.40s, 1 test, 2 errors <<< FAILURES!

[...truncated 299 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:447: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:496: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1296: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:920: There were test failures: 404 suites, 1686 tests, 1 suite-level error, 1 error, 404 ignored (16 assumptions)

Total time: 154 minutes 35 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.8.0_05 -XX:+UseCompressedOops -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



[JENKINS] Lucene-Solr-trunk-Linux (32bit/jdk1.8.0_20-ea-b11) - Build # 10338 - Still Failing!

Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/10338/
Java: 32bit/jdk1.8.0_20-ea-b11 -server -XX:+UseParallelGC

2 tests failed.
FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.ReplicationFactorTest

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

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


FAILED:  org.apache.solr.cloud.ReplicationFactorTest.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([ED36598782842FE7]:0)




Build Log:
[...truncated 11909 lines...]
   [junit4] Suite: org.apache.solr.cloud.ReplicationFactorTest
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/init-core-data-001
   [junit4]   2> 1258535 T5029 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /uy_na/hu
   [junit4]   2> 1258539 T5029 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> 1258539 T5029 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1258540 T5030 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1258640 T5029 oasc.ZkTestServer.run start zk server on port:32978
   [junit4]   2> 1258641 T5029 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1267896 T5033 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 9253ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
   [junit4]   2> 1267897 T5036 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ded2a3 name:ZooKeeperConnection Watcher:127.0.0.1:32978 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1267897 T5029 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1267898 T5029 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1267901 T5029 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1267902 T5038 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1baf262 name:ZooKeeperConnection Watcher:127.0.0.1:32978/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1267903 T5029 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1267903 T5029 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 1267909 T5029 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 1267911 T5029 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 1267912 T5029 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 1267913 T5029 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> 1267914 T5029 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 1267916 T5029 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 1267916 T5029 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 1267919 T5029 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> 1267919 T5029 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1267920 T5029 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> 1267921 T5029 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 1267923 T5029 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> 1267923 T5029 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 1267924 T5029 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> 1267925 T5029 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 1267926 T5029 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> 1267926 T5029 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 1267928 T5029 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> 1267929 T5029 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1267930 T5029 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> 1267930 T5029 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1267932 T5029 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> 1267933 T5029 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 1267934 T5029 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> 1267934 T5029 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 1268164 T5029 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1268166 T5029 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:33762
   [junit4]   2> 1268166 T5029 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1268167 T5029 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1268167 T5029 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-002
   [junit4]   2> 1268167 T5029 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-002/'
   [junit4]   2> 1268180 T5029 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-002/solr.xml
   [junit4]   2> 1268188 T5029 oasc.CoreContainer.<init> New CoreContainer 2908825
   [junit4]   2> 1268188 T5029 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-002/]
   [junit4]   2> 1268189 T5029 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1268189 T5029 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1268189 T5029 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1268189 T5029 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1268190 T5029 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1268190 T5029 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1268190 T5029 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1268191 T5029 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1268191 T5029 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1268191 T5029 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1268192 T5029 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1268192 T5029 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1268192 T5029 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:32978/solr
   [junit4]   2> 1268193 T5029 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1268194 T5029 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1268195 T5049 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@de42f2 name:ZooKeeperConnection Watcher:127.0.0.1:32978 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1268196 T5029 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1268197 T5029 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1268198 T5051 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@92b0a1 name:ZooKeeperConnection Watcher:127.0.0.1:32978/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1268198 T5029 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1268199 T5029 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1268201 T5029 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1268202 T5029 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 1268204 T5029 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 1268205 T5029 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 1268207 T5029 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1268207 T5029 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42921_uy_na%2Fhu
   [junit4]   2> 1268208 T5029 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42921_uy_na%2Fhu
   [junit4]   2> 1268209 T5029 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1268215 T5029 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1268218 T5029 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:42921_uy_na%2Fhu
   [junit4]   2> 1268218 T5029 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1268220 T5029 oasc.Overseer.start Overseer (id=91786660526030851-127.0.0.1:42921_uy_na%2Fhu-n_0000000000) starting
   [junit4]   2> 1268221 T5029 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1268230 T5053 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1268230 T5029 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1268232 T5029 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1268233 T5029 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1268236 T5052 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1268239 T5054 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 1268239 T5054 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1268244 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1268244 T5054 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1268245 T5052 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1268246 T5052 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:42921/uy_na/hu",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:42921_uy_na%2Fhu",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1268246 T5052 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 1268246 T5052 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1268252 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1268253 T5051 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> 1269244 T5054 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1269245 T5054 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 1269246 T5054 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1269246 T5054 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 1269247 T5054 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1269248 T5054 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-002/collection1/'
   [junit4]   2> 1269249 T5054 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-002/collection1/lib/.svn/' to classloader
   [junit4]   2> 1269249 T5054 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-002/collection1/lib/classes/' to classloader
   [junit4]   2> 1269250 T5054 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-002/collection1/lib/README' to classloader
   [junit4]   2> 1269283 T5054 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
   [junit4]   2> 1269297 T5054 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1269298 T5054 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1269302 T5054 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1269389 T5054 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1269393 T5054 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1269394 T5054 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1269405 T5054 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1269407 T5054 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1269409 T5054 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1269410 T5054 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1269410 T5054 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1269410 T5054 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1269411 T5054 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1269411 T5054 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1269411 T5054 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 1269411 T5054 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1269412 T5054 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-002/collection1/, dataDir=./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-001/control/data/
   [junit4]   2> 1269412 T5054 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@e92762
   [junit4]   2> 1269412 T5054 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-001/control/data
   [junit4]   2> 1269412 T5054 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-001/control/data/index/
   [junit4]   2> 1269413 T5054 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-001/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1269413 T5054 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-001/control/data/index
   [junit4]   2> 1269413 T5054 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@75337b
   [junit4]   2> 1269414 T5054 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1956f3b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@217f39),segFN=segments_1,generation=1}
   [junit4]   2> 1269414 T5054 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1269417 T5054 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1269418 T5054 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1269418 T5054 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1269418 T5054 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1269419 T5054 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1269419 T5054 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1269419 T5054 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1269420 T5054 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1269420 T5054 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1269421 T5054 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1269421 T5054 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1269421 T5054 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1269422 T5054 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1269422 T5054 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1269423 T5054 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1269423 T5054 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1269423 T5054 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 1269426 T5054 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1269427 T5054 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1269428 T5054 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1269428 T5054 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=20, maxMergeAtOnceExplicit=47, maxMergedSegmentMB=19.9609375, floorSegmentMB=1.8818359375, forceMergeDeletesPctAllowed=7.99573033508194, segmentsPerTier=18.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 1269429 T5054 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1956f3b lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@217f39),segFN=segments_1,generation=1}
   [junit4]   2> 1269429 T5054 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1269430 T5054 oass.SolrIndexSearcher.<init> Opening Searcher@53938e[collection1] main
   [junit4]   2> 1269430 T5054 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 1269431 T5054 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1269431 T5054 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 1269432 T5054 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1269433 T5054 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 1269433 T5054 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1269434 T5054 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 1269434 T5054 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1269434 T5054 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 1269435 T5054 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 1269437 T5055 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@53938e[collection1] main{UninvertingDirectoryReader()}
   [junit4]   2> 1269438 T5054 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1269439 T5058 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:42921/uy_na/hu collection:control_collection shard:shard1
   [junit4]   2> 1269439 T5029 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 1269440 T5058 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 1269440 T5029 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1269446 T5029 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1269448 T5061 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@cefde7 name:ZooKeeperConnection Watcher:127.0.0.1:32978/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1269448 T5029 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1269448 T5058 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1269449 T5029 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1269450 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1269451 T5058 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1269451 T5058 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 1269452 T5029 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 1269452 T5052 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> ASYNC  NEW_CORE C1432 name=collection1 org.apache.solr.core.SolrCore@6b75e9 url=http://127.0.0.1:42921/uy_na/hu/collection1 node=127.0.0.1:42921_uy_na%2Fhu C1432_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:42921/uy_na/hu, core=collection1, node_name=127.0.0.1:42921_uy_na%2Fhu}
   [junit4]   2> 1269452 T5058 C1432 P42921 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:42921/uy_na/hu/collection1/
   [junit4]   2> 1269453 T5058 C1432 P42921 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1269454 T5058 C1432 P42921 oasc.SyncStrategy.syncToMe http://127.0.0.1:42921/uy_na/hu/collection1/ has no replicas
   [junit4]   2> 1269454 T5058 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:42921/uy_na/hu/collection1/ shard1
   [junit4]   2> 1269455 T5058 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 1269455 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1269462 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1269467 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1269569 T5051 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> 1269569 T5061 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> 1269613 T5058 oasc.ZkController.register We are http://127.0.0.1:42921/uy_na/hu/collection1/ and leader is http://127.0.0.1:42921/uy_na/hu/collection1/
   [junit4]   2> 1269614 T5058 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:42921/uy_na/hu
   [junit4]   2> 1269614 T5058 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1269614 T5058 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 1269614 T5058 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1269615 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1269615 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1269616 T5058 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1269616 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1269616 T5052 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1269617 T5052 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:42921/uy_na/hu",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:42921_uy_na%2Fhu",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 1269618 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1269708 T5029 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 1269709 T5029 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1269711 T5029 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:47636
   [junit4]   2> 1269712 T5029 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1269712 T5029 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1269713 T5029 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-003
   [junit4]   2> 1269713 T5029 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-003/'
   [junit4]   2> 1269720 T5061 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> 1269720 T5051 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> 1269733 T5029 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-003/solr.xml
   [junit4]   2> 1269740 T5029 oasc.CoreContainer.<init> New CoreContainer 17752115
   [junit4]   2> 1269740 T5029 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-003/]
   [junit4]   2> 1269741 T5029 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1269741 T5029 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1269741 T5029 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1269741 T5029 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1269742 T5029 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1269742 T5029 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1269742 T5029 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1269743 T5029 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1269743 T5029 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1269743 T5029 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1269744 T5029 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1269744 T5029 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1269744 T5029 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:32978/solr
   [junit4]   2> 1269745 T5029 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1269746 T5029 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1269747 T5072 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@14e3069 name:ZooKeeperConnection Watcher:127.0.0.1:32978 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1269747 T5029 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1269749 T5029 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1269750 T5074 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@136276e name:ZooKeeperConnection Watcher:127.0.0.1:32978/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1269750 T5029 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1269756 T5029 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1270759 T5029 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49374_uy_na%2Fhu
   [junit4]   2> 1270761 T5029 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49374_uy_na%2Fhu
   [junit4]   2> 1270785 T5075 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 1270785 T5075 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1270786 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1270786 T5075 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1270786 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1270787 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1270789 T5052 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1270790 T5052 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:49374/uy_na/hu",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49374_uy_na%2Fhu",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1270790 T5052 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
   [junit4]   2> 1270790 T5052 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 1270793 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1270896 T5061 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1270896 T5074 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1270896 T5051 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1271787 T5075 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1271787 T5075 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1271788 T5075 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1271789 T5075 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1271790 T5075 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1271790 T5075 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-003/collection1/'
   [junit4]   2> 1271791 T5075 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-003/collection1/lib/.svn/' to classloader
   [junit4]   2> 1271792 T5075 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-003/collection1/lib/classes/' to classloader
   [junit4]   2> 1271792 T5075 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-003/collection1/lib/README' to classloader
   [junit4]   2> 1271842 T5075 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
   [junit4]   2> 1271857 T5075 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1271859 T5075 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1271863 T5075 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1271956 T5075 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1271960 T5075 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1271961 T5075 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1271973 T5075 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1271975 T5075 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1271978 T5075 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1271979 T5075 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1271980 T5075 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1271980 T5075 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1271981 T5075 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1271982 T5075 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1271982 T5075 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 1271982 T5075 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1271983 T5075 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-003/collection1/, dataDir=./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-001/jetty1/
   [junit4]   2> 1271983 T5075 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@e92762
   [junit4]   2> 1271984 T5075 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-001/jetty1
   [junit4]   2> 1271984 T5075 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-001/jetty1/index/
   [junit4]   2> 1271984 T5075 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-001/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 1271985 T5075 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-001/jetty1/index
   [junit4]   2> 1271985 T5075 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@f6913e
   [junit4]   2> 1271986 T5075 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@f1533e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f053fd),segFN=segments_1,generation=1}
   [junit4]   2> 1271986 T5075 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1271990 T5075 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1271991 T5075 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1271991 T5075 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1271992 T5075 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1271992 T5075 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1271992 T5075 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1271993 T5075 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1271993 T5075 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1271994 T5075 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1271994 T5075 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1271995 T5075 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1271995 T5075 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1271995 T5075 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1271996 T5075 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1271996 T5075 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1271997 T5075 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1271998 T5075 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 1272000 T5075 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1272002 T5075 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1272002 T5075 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1272003 T5075 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=20, maxMergeAtOnceExplicit=47, maxMergedSegmentMB=19.9609375, floorSegmentMB=1.8818359375, forceMergeDeletesPctAllowed=7.99573033508194, segmentsPerTier=18.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 1272003 T5075 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@f1533e lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@f053fd),segFN=segments_1,generation=1}
   [junit4]   2> 1272004 T5075 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1272004 T5075 oass.SolrIndexSearcher.<init> Opening Searcher@1c7dd58[collection1] main
   [junit4]   2> 1272004 T5075 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1272006 T5075 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1272006 T5075 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 1272007 T5075 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1272007 T5075 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 1272008 T5075 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1272008 T5075 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 1272009 T5075 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1272009 T5075 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 1272009 T5075 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 1272012 T5076 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1c7dd58[collection1] main{UninvertingDirectoryReader()}
   [junit4]   2> 1272014 T5075 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1272015 T5079 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49374/uy_na/hu collection:collection1 shard:shard2
   [junit4]   2> 1272016 T5029 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 1272017 T5029 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1272017 T5079 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 1272023 T5079 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 1272025 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1272025 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1272025 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1272026 T5079 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1272026 T5079 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C1433 name=collection1 org.apache.solr.core.SolrCore@10a7f5b url=http://127.0.0.1:49374/uy_na/hu/collection1 node=127.0.0.1:49374_uy_na%2Fhu C1433_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:49374/uy_na/hu, core=collection1, node_name=127.0.0.1:49374_uy_na%2Fhu}
   [junit4]   2> 1272026 T5079 C1433 P49374 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49374/uy_na/hu/collection1/
   [junit4]   2> 1272027 T5079 C1433 P49374 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1272027 T5079 C1433 P49374 oasc.SyncStrategy.syncToMe http://127.0.0.1:49374/uy_na/hu/collection1/ has no replicas
   [junit4]   2> 1272027 T5079 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49374/uy_na/hu/collection1/ shard2
   [junit4]   2> 1272028 T5079 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 1272028 T5052 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1272031 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1272034 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1272040 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1272141 T5051 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1272141 T5074 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1272141 T5061 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1272185 T5079 oasc.ZkController.register We are http://127.0.0.1:49374/uy_na/hu/collection1/ and leader is http://127.0.0.1:49374/uy_na/hu/collection1/
   [junit4]   2> 1272185 T5079 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49374/uy_na/hu
   [junit4]   2> 1272185 T5079 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1272185 T5079 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 1272186 T5079 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1272187 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1272187 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1272187 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1272187 T5079 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1272188 T5052 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1272189 T5052 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:49374/uy_na/hu",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49374_uy_na%2Fhu",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 1272190 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1272257 T5029 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 1272258 T5029 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1272260 T5029 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:48964
   [junit4]   2> 1272261 T5029 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1272261 T5029 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1272262 T5029 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-004
   [junit4]   2> 1272263 T5029 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-004/'
   [junit4]   2> 1272278 T5029 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-004/solr.xml
   [junit4]   2> 1272285 T5029 oasc.CoreContainer.<init> New CoreContainer 26643624
   [junit4]   2> 1272285 T5029 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-004/]
   [junit4]   2> 1272286 T5029 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1272286 T5029 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1272287 T5029 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1272287 T5029 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1272287 T5029 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1272287 T5029 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1272288 T5029 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1272288 T5029 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1272288 T5029 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1272289 T5029 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1272289 T5029 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1272290 T5029 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1272290 T5029 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:32978/solr
   [junit4]   2> 1272290 T5029 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1272291 T5029 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1272291 T5074 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1272291 T5061 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1272291 T5051 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
   [junit4]   2> 1272292 T5091 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a53d8a name:ZooKeeperConnection Watcher:127.0.0.1:32978 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1272293 T5029 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1272295 T5029 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1272297 T5093 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@74645e name:ZooKeeperConnection Watcher:127.0.0.1:32978/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1272297 T5029 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1272307 T5029 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1273309 T5029 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56802_uy_na%2Fhu
   [junit4]   2> 1273311 T5029 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:56802_uy_na%2Fhu
   [junit4]   2> 1273321 T5094 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 1273321 T5094 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1273322 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1273322 T5094 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1273323 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1273323 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1273324 T5052 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1273325 T5052 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:56802/uy_na/hu",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:56802_uy_na%2Fhu",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1273325 T5052 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 1273326 T5052 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 1273329 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1273431 T5093 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1273431 T5051 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1273431 T5074 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1273431 T5061 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1274323 T5094 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1274324 T5094 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1274324 T5094 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1274324 T5094 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1274325 T5094 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1274325 T5094 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-004/collection1/'
   [junit4]   2> 1274326 T5094 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-004/collection1/lib/.svn/' to classloader
   [junit4]   2> 1274326 T5094 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-004/collection1/lib/classes/' to classloader
   [junit4]   2> 1274326 T5094 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-004/collection1/lib/README' to classloader
   [junit4]   2> 1274344 T5094 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
   [junit4]   2> 1274353 T5094 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1274354 T5094 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1274358 T5094 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1274453 T5094 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1274457 T5094 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1274458 T5094 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1274464 T5094 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1274466 T5094 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1274467 T5094 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1274468 T5094 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1274468 T5094 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1274468 T5094 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1274469 T5094 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1274469 T5094 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1274469 T5094 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 1274470 T5094 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1274470 T5094 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-004/collection1/, dataDir=./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-001/jetty2/
   [junit4]   2> 1274470 T5094 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@e92762
   [junit4]   2> 1274471 T5094 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-001/jetty2
   [junit4]   2> 1274471 T5094 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-001/jetty2/index/
   [junit4]   2> 1274471 T5094 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-001/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 1274471 T5094 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-001/jetty2/index
   [junit4]   2> 1274472 T5094 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@682fae
   [junit4]   2> 1274472 T5094 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@834c70 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9a1a9f),segFN=segments_1,generation=1}
   [junit4]   2> 1274472 T5094 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1274475 T5094 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1274475 T5094 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1274475 T5094 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1274475 T5094 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1274476 T5094 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1274476 T5094 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1274476 T5094 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1274476 T5094 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1274476 T5094 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1274477 T5094 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1274477 T5094 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1274477 T5094 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1274478 T5094 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1274478 T5094 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1274478 T5094 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1274479 T5094 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1274479 T5094 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 1274480 T5094 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1274481 T5094 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1274482 T5094 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1274482 T5094 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=20, maxMergeAtOnceExplicit=47, maxMergedSegmentMB=19.9609375, floorSegmentMB=1.8818359375, forceMergeDeletesPctAllowed=7.99573033508194, segmentsPerTier=18.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 1274482 T5094 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@834c70 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@9a1a9f),segFN=segments_1,generation=1}
   [junit4]   2> 1274483 T5094 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1274483 T5094 oass.SolrIndexSearcher.<init> Opening Searcher@b2cb66[collection1] main
   [junit4]   2> 1274483 T5094 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1274484 T5094 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1274484 T5094 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 1274484 T5094 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1274485 T5094 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 1274485 T5094 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1274485 T5094 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 1274485 T5094 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1274486 T5094 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 1274486 T5094 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 1274487 T5095 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@b2cb66[collection1] main{UninvertingDirectoryReader()}
   [junit4]   2> 1274489 T5094 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1274489 T5098 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:56802/uy_na/hu collection:collection1 shard:shard3
   [junit4]   2> 1274490 T5029 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 1274490 T5029 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1274490 T5098 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 1274493 T5098 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard3
   [junit4]   2> 1274494 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1274495 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1274495 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1274495 T5098 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1274495 T5098 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 1274495 T5052 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> ASYNC  NEW_CORE C1434 name=collection1 org.apache.solr.core.SolrCore@4caee8 url=http://127.0.0.1:56802/uy_na/hu/collection1 node=127.0.0.1:56802_uy_na%2Fhu C1434_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:56802/uy_na/hu, core=collection1, node_name=127.0.0.1:56802_uy_na%2Fhu}
   [junit4]   2> 1274495 T5098 C1434 P56802 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:56802/uy_na/hu/collection1/
   [junit4]   2> 1274496 T5098 C1434 P56802 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1274496 T5098 C1434 P56802 oasc.SyncStrategy.syncToMe http://127.0.0.1:56802/uy_na/hu/collection1/ has no replicas
   [junit4]   2> 1274496 T5098 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:56802/uy_na/hu/collection1/ shard3
   [junit4]   2> 1274497 T5098 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
   [junit4]   2> 1274497 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1274500 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1274502 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1274603 T5093 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1274603 T5051 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1274603 T5074 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1274603 T5061 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1274651 T5098 oasc.ZkController.register We are http://127.0.0.1:56802/uy_na/hu/collection1/ and leader is http://127.0.0.1:56802/uy_na/hu/collection1/
   [junit4]   2> 1274651 T5098 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:56802/uy_na/hu
   [junit4]   2> 1274651 T5098 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1274651 T5098 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 1274652 T5098 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1274653 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1274653 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1274653 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1274654 T5098 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1274654 T5052 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1274654 T5052 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:56802/uy_na/hu",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:56802_uy_na%2Fhu",
   [junit4]   2> 	  "shard":"shard3",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 1274656 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1274730 T5029 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
   [junit4]   2> 1274731 T5029 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1274733 T5029 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:54201
   [junit4]   2> 1274734 T5029 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1274734 T5029 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1274734 T5029 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-005
   [junit4]   2> 1274735 T5029 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-005/'
   [junit4]   2> 1274746 T5029 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-005/solr.xml
   [junit4]   2> 1274752 T5029 oasc.CoreContainer.<init> New CoreContainer 16933891
   [junit4]   2> 1274753 T5029 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-005/]
   [junit4]   2> 1274753 T5029 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1274753 T5029 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1274754 T5029 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1274754 T5029 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1274754 T5029 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1274755 T5029 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1274755 T5029 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1274755 T5029 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1274756 T5029 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1274756 T5029 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1274756 T5029 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1274757 T5029 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1274757 T5029 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:32978/solr
   [junit4]   2> 1274758 T5029 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1274758 T5029 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1274763 T5093 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1274763 T5051 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1274763 T5110 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1daed70 name:ZooKeeperConnection Watcher:127.0.0.1:32978 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1274763 T5061 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1274764 T5029 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1274763 T5074 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
   [junit4]   2> 1274766 T5029 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1274767 T5112 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1dacea1 name:ZooKeeperConnection Watcher:127.0.0.1:32978/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1274767 T5029 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1274771 T5029 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1275774 T5029 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:44192_uy_na%2Fhu
   [junit4]   2> 1275776 T5029 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:44192_uy_na%2Fhu
   [junit4]   2> 1275785 T5113 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 1275786 T5113 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1275787 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1275787 T5113 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1275787 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1275788 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1275790 T5052 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1275790 T5052 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"http://127.0.0.1:44192/uy_na/hu",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:44192_uy_na%2Fhu",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1275791 T5052 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 1275791 T5052 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1275794 T5051 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1275896 T5093 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 1275896 T5112 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 1275896 T5051 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 1275896 T5061 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 1275896 T5074 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 1276788 T5113 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1276788 T5113 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1276789 T5113 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1276789 T5113 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1276790 T5113 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1276790 T5113 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-005/collection1/'
   [junit4]   2> 1276790 T5113 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-005/collection1/lib/.svn/' to classloader
   [junit4]   2> 1276790 T5113 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-005/collection1/lib/classes/' to classloader
   [junit4]   2> 1276791 T5113 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J1/solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-005/collection1/lib/README' to classloader
   [junit4]   2> 1276809 T5113 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_5_0
   [junit4]   2> 1276818 T5113 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1276819 T5113 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1276823 T5113 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1276918 T5113 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1276922 T5113 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1276923 T5113 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1276930 T5113 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1276932 T5113 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1276935 T5113 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1276935 T5113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1276936 T5113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1276936 T5113 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1276937 T5113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1276937 T5113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1276937 T5113 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 1276938 T5113 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1276938 T5113 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-005/collection1/, dataDir=./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-001/jetty3/
   [junit4]   2> 1276938 T5113 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@e92762
   [junit4]   2> 1276939 T5113 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-001/jetty3
   [junit4]   2> 1276939 T5113 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-001/jetty3/index/
   [junit4]   2> 1276939 T5113 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.ReplicationFactorTest-ED36598782842FE7-001/tempDir-001/jetty3/index' doesn't exist. Creating new index...
   [junit4]   2> 1276940 T5113 oasc.CachingDirectoryFact

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

mPropertiesInvariantRule.java:55)
   [junit4]   2> 	        at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
   [junit4]   2> 	        at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
   [junit4]   2> 	        at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
   [junit4]   2> 	        at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
   [junit4]   2> 	        at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	        at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
   [junit4]   2> 	        at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
   [junit4]   2> 	        at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
   [junit4]   2> 	        at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 8482296 T5029 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: test params are: codec=Lucene46: {_version_=TestBloomFilteredLucene41Postings(BloomFilteringPostingsFormat(Lucene41(blocksize=128))), multiDefault=Pulsing41(freqCutoff=12 minBlockSize=48 maxBlockSize=134), a_t=TestBloomFilteredLucene41Postings(BloomFilteringPostingsFormat(Lucene41(blocksize=128))), intDefault=TestBloomFilteredLucene41Postings(BloomFilteringPostingsFormat(Lucene41(blocksize=128))), id=PostingsFormat(name=FSTPulsing41), text=FSTOrd41, range_facet_l=TestBloomFilteredLucene41Postings(BloomFilteringPostingsFormat(Lucene41(blocksize=128))), timestamp=TestBloomFilteredLucene41Postings(BloomFilteringPostingsFormat(Lucene41(blocksize=128)))}, docValues:{timestamp=DocValuesFormat(name=Memory)}, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=pt_PT, timezone=Antarctica/DumontDUrville
   [junit4]   2> NOTE: Linux 3.8.0-39-generic i386/Oracle Corporation 1.8.0_20-ea (32-bit)/cpus=8,threads=2,free=105737136,total=377487360
   [junit4]   2> NOTE: All tests run in this JVM: [FieldFacetTest, TestXIncludeConfig, DistribCursorPagingTest, BasicZkTest, TestManagedResource, TestAtomicUpdateErrorCases, TestLRUCache, TestManagedSynonymFilterFactory, TestFastOutputStream, TestAnalyzedSuggestions, TestZkChroot, LegacyHTMLStripCharFilterTest, MultiThreadedOCPTest, ChaosMonkeySafeLeaderTest, DocumentAnalysisRequestHandlerTest, SimplePostToolTest, ConnectionManagerTest, TestSolr4Spatial, OpenExchangeRatesOrgProviderTest, HardAutoCommitTest, TestLMDirichletSimilarityFactory, AbstractAnalyticsStatsTest, NumericFieldsTest, TestIndexingPerformance, TestNoOpRegenerator, TestStressReorder, SolrCmdDistributorTest, ZkSolrClientTest, TestJmxIntegration, DefaultValueUpdateProcessorTest, TestQueryTypes, MigrateRouteKeyTest, TestSchemaNameResource, TestDocBasedVersionConstraints, TestCollapseQParserPlugin, CoreContainerCoreInitFailuresTest, StandardRequestHandlerTest, TestFileDictionaryLookup, EnumFieldTest, HdfsBasicDistributedZkTest, TestSolrJ, FieldFacetExtrasTest, TestOmitPositions, TestPartialUpdateDeduplication, TestRecoveryHdfs, TestComponentsName, TestHighFrequencyDictionaryFactory, TestPhraseSuggestions, TestRandomFaceting, TestSweetSpotSimilarityFactory, CollectionsAPIDistributedZkTest, ShardRoutingCustomTest, TestBinaryResponseWriter, BlockDirectoryTest, SSLMigrationTest, TestFiltering, BasicDistributedZk2Test, SuggesterWFSTTest, CoreMergeIndexesAdminHandlerTest, RequestHandlersTest, TestManagedStopFilterFactory, TestDFRSimilarityFactory, NoCacheHeaderTest, ResourceLoaderTest, DocValuesMissingTest, TestFoldingMultitermQuery, TestDistributedGrouping, LeaderElectionIntegrationTest, JSONWriterTest, BadIndexSchemaTest, HdfsUnloadDistributedZkTest, SpellCheckCollatorTest, DocExpirationUpdateProcessorFactoryTest, ZkNodePropsTest, TestDistributedSearch, TestSolrCoreProperties, DocValuesMultiTest, SystemInfoHandlerTest, TestQuerySenderNoQuery, CurrencyFieldXmlFileTest, DistanceFunctionTest, ConvertedLegacyTest, SuggesterTSTTest, DeleteInactiveReplicaTest, TestRecovery, TestArbitraryIndexDir, SolrCoreCheckLockOnStartupTest, DateMathParserTest, OpenCloseCoreStressTest, TestDistribDocBasedVersion, TestMiniSolrCloudCluster, TestFreeTextSuggestions, SolrPluginUtilsTest, TestCloudManagedSchema, CurrencyFieldOpenExchangeTest, SuggestComponentTest, TestStressLucene, FullSolrCloudDistribCmdsTest, TestSchemaSimilarityResource, OutputWriterTest, TestBadConfig, HighlighterTest, DistributedQueryElevationComponentTest, TestCoreDiscovery, SignatureUpdateProcessorFactoryTest, SolrRequestParserTest, TestCSVLoader, TestUpdate, QueryEqualityTest, TestSolrDeletionPolicy1, XsltUpdateRequestHandlerTest, CacheHeaderTest, TestSurroundQueryParser, DisMaxRequestHandlerTest, DirectSolrSpellCheckerTest, PrimitiveFieldTypeTest, TermsComponentTest, DocumentBuilderTest, PathHierarchyTokenizerFactoryTest, RequiredFieldsTest, TestSolrQueryParser, IndexSchemaRuntimeFieldTest, TestCollationField, MBeansHandlerTest, BinaryUpdateRequestHandlerTest, PingRequestHandlerTest, HighlighterConfigTest, UpdateParamsTest, CopyFieldTest, TestStressRecovery, SpellingQueryConverterTest, TestUtils, UUIDFieldTest, CircularListTest, TestRTGBase, SolrTestCaseJ4Test, TestDistributedMissingSort, TestHighlightDedupGrouping, NoFacetTest, ExpressionTest, RangeFacetTest, FunctionTest, AliasIntegrationTest, DeleteReplicaTest, DistribDocExpirationUpdateProcessorTest, ReplicationFactorTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=ReplicationFactorTest -Dtests.seed=ED36598782842FE7 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=pt_PT -Dtests.timezone=Antarctica/DumontDUrville -Dtests.file.encoding=ISO-8859-1
   [junit4] ERROR   0.00s J1 | ReplicationFactorTest (suite) <<<
   [junit4]    > Throwable #1: java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([ED36598782842FE7]:0)
   [junit4] Completed on J1 in 7223.80s, 1 test, 2 errors <<< FAILURES!

[...truncated 11 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:447: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/common-build.xml:496: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:1296: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/lucene/common-build.xml:920: There were test failures: 406 suites, 1688 tests, 1 suite-level error, 1 error, 37 ignored (16 assumptions)

Total time: 172 minutes 52 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.8.0_20-ea-b11 -server -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure