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 06:35:37 UTC

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

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