lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-4.x-Linux (32bit/jdk1.8.0_20-ea-b15) - Build # 10272 - Failure!
Date Mon, 26 May 2014 13:51:06 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/10272/
Java: 32bit/jdk1.8.0_20-ea-b15 -client -XX:+UseSerialGC

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


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




Build Log:
[...truncated 12220 lines...]
   [junit4] Suite: org.apache.solr.cloud.ReplicationFactorTest
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/init-core-data-001
   [junit4]   2> 1411468 T6665 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 1411472 T6665 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> 1411473 T6665 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 1411474 T6666 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1411574 T6665 oasc.ZkTestServer.run start zk server on port:42443
   [junit4]   2> 1411575 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1413635 T6669 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 2059ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
   [junit4]   2> 1413637 T6672 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1966e7 name:ZooKeeperConnection Watcher:127.0.0.1:42443 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1413637 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1413638 T6665 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1413642 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1413643 T6674 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1185766 name:ZooKeeperConnection Watcher:127.0.0.1:42443/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1413643 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1413643 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 1413648 T6665 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 1413650 T6665 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 1413653 T6665 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 1413655 T6665 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 1413656 T6665 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 1413659 T6665 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
   [junit4]   2> 1413659 T6665 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 1413662 T6665 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1413663 T6665 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1413665 T6665 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 1413665 T6665 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 1413667 T6665 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 1413668 T6665 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 1413670 T6665 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 1413670 T6665 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 1413672 T6665 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 1413673 T6665 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 1413675 T6665 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1413675 T6665 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1413677 T6665 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1413678 T6665 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1413681 T6665 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 1413682 T6665 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 1413684 T6665 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 1413684 T6665 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 1413979 T6665 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1413982 T6665 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:45345
   [junit4]   2> 1413983 T6665 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1413983 T6665 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1413984 T6665 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-002
   [junit4]   2> 1413984 T6665 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-002/'
   [junit4]   2> 1414003 T6665 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-002/solr.xml
   [junit4]   2> 1414016 T6665 oasc.CoreContainer.<init> New CoreContainer 19445973
   [junit4]   2> 1414017 T6665 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-002/]
   [junit4]   2> 1414018 T6665 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1414018 T6665 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1414019 T6665 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1414019 T6665 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1414019 T6665 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1414020 T6665 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1414020 T6665 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1414020 T6665 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1414021 T6665 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1414021 T6665 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1414022 T6665 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1414022 T6665 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1414022 T6665 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:42443/solr
   [junit4]   2> 1414023 T6665 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1414024 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1414026 T6685 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c70e26 name:ZooKeeperConnection Watcher:127.0.0.1:42443 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1414026 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1414029 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1414030 T6687 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@146e85c name:ZooKeeperConnection Watcher:127.0.0.1:42443/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1414030 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1414032 T6665 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1414036 T6665 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1414039 T6665 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 1414042 T6665 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 1414044 T6665 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 1414052 T6665 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1414054 T6665 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:38628_
   [junit4]   2> 1414055 T6665 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:38628_
   [junit4]   2> 1414057 T6665 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1414059 T6665 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1414062 T6665 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:38628_
   [junit4]   2> 1414063 T6665 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1414066 T6665 oasc.Overseer.start Overseer (id=91822818757771267-127.0.0.1:38628_-n_0000000000) starting
   [junit4]   2> 1414070 T6665 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1414078 T6689 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1414079 T6665 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1414081 T6665 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1414083 T6665 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1414085 T6688 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1414087 T6690 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 1414088 T6690 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1414089 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1414089 T6690 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1414090 T6688 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1414091 T6688 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:38628",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:38628_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1414091 T6688 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 1414091 T6688 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1414112 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1414113 T6687 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> 1415089 T6690 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1415090 T6690 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 1415091 T6690 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1415091 T6690 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 1415092 T6690 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1415093 T6690 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-002/collection1/'
   [junit4]   2> 1415094 T6690 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-002/collection1/lib/.svn/' to classloader
   [junit4]   2> 1415094 T6690 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-002/collection1/lib/classes/' to classloader
   [junit4]   2> 1415094 T6690 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-002/collection1/lib/README' to classloader
   [junit4]   2> 1415134 T6690 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
   [junit4]   2> 1415155 T6690 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1415157 T6690 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1415177 T6690 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1415321 T6690 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1415322 T6690 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1415323 T6690 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1415328 T6690 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1415330 T6690 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1415342 T6690 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1415346 T6690 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1415348 T6690 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1415349 T6690 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1415350 T6690 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1415350 T6690 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1415351 T6690 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1415351 T6690 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1415351 T6690 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 1415352 T6690 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1415352 T6690 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-002/collection1/, dataDir=./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-001/control/data/
   [junit4]   2> 1415352 T6690 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@13d8f8c
   [junit4]   2> 1415353 T6690 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-001/control/data
   [junit4]   2> 1415353 T6690 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-001/control/data/index/
   [junit4]   2> 1415353 T6690 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-001/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 1415354 T6690 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-001/control/data/index
   [junit4]   2> 1415354 T6690 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=36, maxMergeAtOnceExplicit=39, maxMergedSegmentMB=70.9189453125, floorSegmentMB=0.40234375, forceMergeDeletesPctAllowed=17.70692626489325, segmentsPerTier=45.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 1415355 T6690 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=BaseDirectoryWrapper(RAMDirectory@c19f89 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1a95da3),segFN=segments_1,generation=1}
   [junit4]   2> 1415355 T6690 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1415358 T6690 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1415359 T6690 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1415359 T6690 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1415359 T6690 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1415360 T6690 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1415360 T6690 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1415360 T6690 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1415361 T6690 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1415361 T6690 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1415370 T6690 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1415371 T6690 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1415371 T6690 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1415371 T6690 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1415372 T6690 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1415373 T6690 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1415373 T6690 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1415375 T6690 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1415378 T6690 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1415378 T6690 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1415379 T6690 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=35, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=64.1328125, floorSegmentMB=0.79296875, forceMergeDeletesPctAllowed=25.647150541703656, segmentsPerTier=36.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 1415379 T6690 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=BaseDirectoryWrapper(RAMDirectory@c19f89 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1a95da3),segFN=segments_1,generation=1}
   [junit4]   2> 1415380 T6690 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1415380 T6690 oass.SolrIndexSearcher.<init> Opening Searcher@5c108e[collection1] main
   [junit4]   2> 1415381 T6690 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 1415382 T6690 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1415382 T6690 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 1415383 T6690 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1415383 T6690 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 1415383 T6690 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1415384 T6690 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 1415385 T6690 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1415385 T6690 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 1415386 T6690 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 1415390 T6691 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5c108e[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1415393 T6690 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1415394 T6694 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:38628 collection:control_collection shard:shard1
   [junit4]   2> 1415395 T6665 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 1415395 T6694 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 1415395 T6665 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1415397 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1415399 T6697 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b04318 name:ZooKeeperConnection Watcher:127.0.0.1:42443/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1415399 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1415400 T6665 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1415402 T6694 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1415402 T6665 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 1415404 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1415404 T6694 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1415404 T6694 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C4176 name=collection1 org.apache.solr.core.SolrCore@efc4f6 url=http://127.0.0.1:38628/collection1 node=127.0.0.1:38628_ C4176_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:38628, core=collection1, node_name=127.0.0.1:38628_}
   [junit4]   2> 1415405 T6694 C4176 P38628 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:38628/collection1/
   [junit4]   2> 1415405 T6694 C4176 P38628 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1415405 T6694 C4176 P38628 oasc.SyncStrategy.syncToMe http://127.0.0.1:38628/collection1/ has no replicas
   [junit4]   2> 1415406 T6694 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:38628/collection1/ shard1
   [junit4]   2> 1415406 T6694 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 1415406 T6688 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1415410 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1415411 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1415414 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1415516 T6687 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> 1415516 T6697 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> 1415562 T6694 oasc.ZkController.register We are http://127.0.0.1:38628/collection1/ and leader is http://127.0.0.1:38628/collection1/
   [junit4]   2> 1415563 T6694 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:38628
   [junit4]   2> 1415563 T6694 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1415563 T6694 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 1415563 T6694 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1415565 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1415565 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1415565 T6694 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1415566 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1415567 T6688 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1415567 T6688 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:38628",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:38628_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 1415570 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1415678 T6697 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> 1415678 T6687 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> 1415709 T6665 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 1415710 T6665 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1415712 T6665 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:43329
   [junit4]   2> 1415713 T6665 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1415714 T6665 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1415714 T6665 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-003
   [junit4]   2> 1415715 T6665 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-003/'
   [junit4]   2> 1415746 T6665 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-003/solr.xml
   [junit4]   2> 1415757 T6665 oasc.CoreContainer.<init> New CoreContainer 32033100
   [junit4]   2> 1415758 T6665 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-003/]
   [junit4]   2> 1415758 T6665 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1415759 T6665 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1415759 T6665 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1415760 T6665 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1415760 T6665 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1415760 T6665 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1415761 T6665 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1415761 T6665 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1415761 T6665 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1415762 T6665 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1415763 T6665 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1415763 T6665 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1415763 T6665 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:42443/solr
   [junit4]   2> 1415764 T6665 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1415765 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1415766 T6708 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@95c0e6 name:ZooKeeperConnection Watcher:127.0.0.1:42443 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1415767 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1415768 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1415769 T6710 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1951efe name:ZooKeeperConnection Watcher:127.0.0.1:42443/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1415770 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1415777 T6665 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1416780 T6665 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42636_
   [junit4]   2> 1416781 T6665 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42636_
   [junit4]   2> 1416783 T6687 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1416783 T6697 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1416784 T6710 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1416788 T6711 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 1416788 T6711 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1416789 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1416789 T6711 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1416789 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1416790 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1416790 T6688 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1416791 T6688 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:42636",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:42636_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1416792 T6688 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
   [junit4]   2> 1416792 T6688 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 1416795 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1416896 T6687 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> 1416896 T6697 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> 1416896 T6710 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> 1417790 T6711 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1417790 T6711 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1417791 T6711 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1417791 T6711 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1417792 T6711 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1417792 T6711 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-003/collection1/'
   [junit4]   2> 1417793 T6711 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-003/collection1/lib/.svn/' to classloader
   [junit4]   2> 1417793 T6711 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-003/collection1/lib/classes/' to classloader
   [junit4]   2> 1417794 T6711 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-003/collection1/lib/README' to classloader
   [junit4]   2> 1417833 T6711 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
   [junit4]   2> 1417844 T6711 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1417845 T6711 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1417855 T6711 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1418002 T6711 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1418002 T6711 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1418003 T6711 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1418008 T6711 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1418010 T6711 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1418026 T6711 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1418029 T6711 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1418032 T6711 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1418033 T6711 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1418033 T6711 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1418034 T6711 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1418034 T6711 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1418035 T6711 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1418035 T6711 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 1418035 T6711 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1418036 T6711 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-003/collection1/, dataDir=./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-001/jetty1/
   [junit4]   2> 1418036 T6711 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@13d8f8c
   [junit4]   2> 1418037 T6711 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-001/jetty1
   [junit4]   2> 1418037 T6711 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-001/jetty1/index/
   [junit4]   2> 1418037 T6711 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-001/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 1418038 T6711 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-001/jetty1/index
   [junit4]   2> 1418038 T6711 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=36, maxMergeAtOnceExplicit=39, maxMergedSegmentMB=70.9189453125, floorSegmentMB=0.40234375, forceMergeDeletesPctAllowed=17.70692626489325, segmentsPerTier=45.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 1418039 T6711 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=BaseDirectoryWrapper(RAMDirectory@1329893 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@99028),segFN=segments_1,generation=1}
   [junit4]   2> 1418039 T6711 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1418043 T6711 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1418043 T6711 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1418044 T6711 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1418044 T6711 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1418044 T6711 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1418044 T6711 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1418045 T6711 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1418045 T6711 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1418045 T6711 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1418046 T6711 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1418047 T6711 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1418047 T6711 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1418047 T6711 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1418048 T6711 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1418048 T6711 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1418049 T6711 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1418051 T6711 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1418052 T6711 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1418053 T6711 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1418054 T6711 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=35, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=64.1328125, floorSegmentMB=0.79296875, forceMergeDeletesPctAllowed=25.647150541703656, segmentsPerTier=36.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 1418054 T6711 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=BaseDirectoryWrapper(RAMDirectory@1329893 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@99028),segFN=segments_1,generation=1}
   [junit4]   2> 1418054 T6711 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1418055 T6711 oass.SolrIndexSearcher.<init> Opening Searcher@16a7234[collection1] main
   [junit4]   2> 1418055 T6711 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1418056 T6711 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1418056 T6711 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 1418057 T6711 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1418057 T6711 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 1418057 T6711 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1418058 T6711 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 1418058 T6711 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1418059 T6711 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 1418059 T6711 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 1418063 T6712 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@16a7234[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1418066 T6711 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1418067 T6715 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:42636 collection:collection1 shard:shard2
   [junit4]   2> 1418067 T6665 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 1418068 T6715 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 1418068 T6665 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1418073 T6715 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 1418075 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1418075 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1418075 T6715 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1418075 T6715 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 1418075 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> ASYNC  NEW_CORE C4177 name=collection1 org.apache.solr.core.SolrCore@9c1959 url=http://127.0.0.1:42636/collection1 node=127.0.0.1:42636_ C4177_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:42636, core=collection1, node_name=127.0.0.1:42636_}
   [junit4]   2> 1418076 T6715 C4177 P42636 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:42636/collection1/
   [junit4]   2> 1418076 T6715 C4177 P42636 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1418077 T6715 C4177 P42636 oasc.SyncStrategy.syncToMe http://127.0.0.1:42636/collection1/ has no replicas
   [junit4]   2> 1418077 T6715 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:42636/collection1/ shard2
   [junit4]   2> 1418077 T6688 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1418077 T6715 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 1418079 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1418083 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1418086 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1418187 T6687 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> 1418187 T6710 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> 1418187 T6697 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> 1418234 T6715 oasc.ZkController.register We are http://127.0.0.1:42636/collection1/ and leader is http://127.0.0.1:42636/collection1/
   [junit4]   2> 1418235 T6715 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:42636
   [junit4]   2> 1418235 T6715 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1418235 T6715 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 1418236 T6715 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1418238 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1418238 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1418239 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1418239 T6715 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1418240 T6688 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1418241 T6688 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:42636",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:42636_",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 1418243 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1418345 T6697 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> 1418345 T6710 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> 1418345 T6687 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> 1418347 T6665 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 1418348 T6665 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1418350 T6665 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52079
   [junit4]   2> 1418351 T6665 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1418351 T6665 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1418351 T6665 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-004
   [junit4]   2> 1418352 T6665 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-004/'
   [junit4]   2> 1418368 T6665 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-004/solr.xml
   [junit4]   2> 1418390 T6665 oasc.CoreContainer.<init> New CoreContainer 2933030
   [junit4]   2> 1418391 T6665 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-004/]
   [junit4]   2> 1418391 T6665 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1418392 T6665 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1418392 T6665 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1418393 T6665 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1418393 T6665 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1418393 T6665 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1418394 T6665 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1418394 T6665 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1418394 T6665 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1418395 T6665 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1418395 T6665 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1418396 T6665 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1418396 T6665 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:42443/solr
   [junit4]   2> 1418397 T6665 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1418397 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1418399 T6727 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b19bb0 name:ZooKeeperConnection Watcher:127.0.0.1:42443 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1418399 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1418401 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1418402 T6729 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a73396 name:ZooKeeperConnection Watcher:127.0.0.1:42443/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1418403 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1418414 T6665 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1419417 T6665 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41370_
   [junit4]   2> 1419418 T6665 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:41370_
   [junit4]   2> 1419420 T6710 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1419420 T6697 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1419420 T6687 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1419420 T6729 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1419424 T6730 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 1419424 T6730 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1419425 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1419426 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1419426 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1419425 T6730 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1419428 T6688 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1419429 T6688 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:41370",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:41370_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1419430 T6688 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 1419430 T6688 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 1419432 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1419536 T6710 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> 1419536 T6697 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> 1419536 T6729 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> 1419536 T6687 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> 1420427 T6730 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1420427 T6730 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1420428 T6730 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1420428 T6730 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1420429 T6730 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1420430 T6730 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-004/collection1/'
   [junit4]   2> 1420430 T6730 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-004/collection1/lib/.svn/' to classloader
   [junit4]   2> 1420431 T6730 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-004/collection1/lib/classes/' to classloader
   [junit4]   2> 1420431 T6730 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-004/collection1/lib/README' to classloader
   [junit4]   2> 1420459 T6730 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
   [junit4]   2> 1420470 T6730 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1420471 T6730 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1420490 T6730 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1420632 T6730 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1420633 T6730 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1420634 T6730 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1420640 T6730 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1420641 T6730 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1420657 T6730 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1420660 T6730 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1420663 T6730 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1420664 T6730 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1420664 T6730 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1420664 T6730 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 1420665 T6730 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 1420665 T6730 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 1420666 T6730 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 1420666 T6730 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 1420666 T6730 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-004/collection1/, dataDir=./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-001/jetty2/
   [junit4]   2> 1420667 T6730 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@13d8f8c
   [junit4]   2> 1420668 T6730 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-001/jetty2
   [junit4]   2> 1420668 T6730 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-001/jetty2/index/
   [junit4]   2> 1420668 T6730 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-001/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 1420668 T6730 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-001/jetty2/index
   [junit4]   2> 1420669 T6730 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=36, maxMergeAtOnceExplicit=39, maxMergedSegmentMB=70.9189453125, floorSegmentMB=0.40234375, forceMergeDeletesPctAllowed=17.70692626489325, segmentsPerTier=45.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 1420670 T6730 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=BaseDirectoryWrapper(RAMDirectory@48b992 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5aa6c9),segFN=segments_1,generation=1}
   [junit4]   2> 1420670 T6730 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1420674 T6730 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1420674 T6730 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1420674 T6730 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1420675 T6730 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1420675 T6730 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1420675 T6730 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1420676 T6730 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1420676 T6730 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1420676 T6730 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1420677 T6730 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1420678 T6730 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1420678 T6730 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1420679 T6730 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1420679 T6730 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1420680 T6730 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1420681 T6730 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1420683 T6730 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1420684 T6730 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1420685 T6730 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1420685 T6730 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=35, maxMergeAtOnceExplicit=26, maxMergedSegmentMB=64.1328125, floorSegmentMB=0.79296875, forceMergeDeletesPctAllowed=25.647150541703656, segmentsPerTier=36.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 1420686 T6730 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=BaseDirectoryWrapper(RAMDirectory@48b992 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5aa6c9),segFN=segments_1,generation=1}
   [junit4]   2> 1420686 T6730 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1420687 T6730 oass.SolrIndexSearcher.<init> Opening Searcher@1b74cfd[collection1] main
   [junit4]   2> 1420687 T6730 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1420688 T6730 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1420688 T6730 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 1420689 T6730 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 1420689 T6730 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 1420689 T6730 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1420690 T6730 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 1420690 T6730 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 1420690 T6730 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 1420691 T6730 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 1420696 T6731 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1b74cfd[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1420698 T6730 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1420699 T6734 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:41370 collection:collection1 shard:shard3
   [junit4]   2> 1420700 T6665 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 1420700 T6665 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1420700 T6734 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 1420705 T6734 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard3
   [junit4]   2> 1420707 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1420707 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1420707 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1420708 T6734 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1420708 T6688 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1420708 T6734 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C4178 name=collection1 org.apache.solr.core.SolrCore@5a925d url=http://127.0.0.1:41370/collection1 node=127.0.0.1:41370_ C4178_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:41370, core=collection1, node_name=127.0.0.1:41370_}
   [junit4]   2> 1420709 T6734 C4178 P41370 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:41370/collection1/
   [junit4]   2> 1420709 T6734 C4178 P41370 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1420710 T6734 C4178 P41370 oasc.SyncStrategy.syncToMe http://127.0.0.1:41370/collection1/ has no replicas
   [junit4]   2> 1420710 T6734 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:41370/collection1/ shard3
   [junit4]   2> 1420710 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1420711 T6734 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
   [junit4]   2> 1421002 T6665 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
   [junit4]   2> 1421003 T6665 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1421005 T6665 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:56981
   [junit4]   2> 1421005 T6665 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1421006 T6665 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1421006 T6665 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-005
   [junit4]   2> 1421007 T6665 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-005/'
   [junit4]   2> 1421023 T6665 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-005/solr.xml
   [junit4]   2> 1421037 T6665 oasc.CoreContainer.<init> New CoreContainer 6024238
   [junit4]   2> 1421037 T6665 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-005/]
   [junit4]   2> 1421038 T6665 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1421039 T6665 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1421040 T6665 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1421040 T6665 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1421041 T6665 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1421041 T6665 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1421042 T6665 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1421042 T6665 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1421043 T6665 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1421044 T6665 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1421045 T6665 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1421045 T6665 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1421046 T6665 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:42443/solr
   [junit4]   2> 1421046 T6665 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1421048 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1422396 T6669 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 1682ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
   [junit4]   2> 1422404 T6746 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f083 name:ZooKeeperConnection Watcher:127.0.0.1:42443 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1422404 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1422418 T6729 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> 1422418 T6697 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> 1422418 T6687 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> 1422418 T6710 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> 1422458 T6665 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1422498 T6748 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1646f5d name:ZooKeeperConnection Watcher:127.0.0.1:42443/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1422499 T6665 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1422499 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1422500 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1422500 T6688 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1422578 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1422620 T6665 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1422698 T6710 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> 1422698 T6748 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> 1422698 T6687 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> 1422698 T6729 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> 1422698 T6697 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> 1422728 T6734 oasc.ZkController.register We are http://127.0.0.1:41370/collection1/ and leader is http://127.0.0.1:41370/collection1/
   [junit4]   2> 1422729 T6734 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:41370
   [junit4]   2> 1422729 T6734 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1422730 T6734 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 1422730 T6734 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1424118 T6669 oazsp.FileTxnLog.commit WARN fsync-ing the write ahead log in SyncThread:0 took 1385ms which will adversely effect operation latency. See the ZooKeeper troubleshooting guide
   [junit4]   2> 1424118 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1424119 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1424119 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1424119 T6734 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1424119 T6665 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42164_
   [junit4]   2> 1424120 T6688 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1424121 T6665 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42164_
   [junit4]   2> 1424122 T6688 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:41370",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:41370_",
   [junit4]   2> 	  "shard":"shard3",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 1424124 T6729 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1424125 T6697 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1424125 T6710 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1424125 T6748 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1424130 T6749 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 1424130 T6749 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1424131 T6749 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1424228 T6688 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:42164",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:42164_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1424228 T6688 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 1424228 T6688 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1424231 T6710 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> 1424231 T6748 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> 1424231 T6697 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> 1424231 T6729 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> 1424235 T6687 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1424235 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1424235 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1424235 T6687 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1424236 T6687 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> 1425131 T6749 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1425132 T6749 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1425132 T6749 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1425133 T6749 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1425134 T6749 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1425134 T6749 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-005/collection1/'
   [junit4]   2> 1425135 T6749 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-005/collection1/lib/.svn/' to classloader
   [junit4]   2> 1425135 T6749 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-005/collection1/lib/classes/' to classloader
   [junit4]   2> 1425135 T6749 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.ReplicationFactorTest-C8E31AF8470B2BB5-001/tempDir-005/collection1/lib/README' to classloader
   [junit4]   2> 1425181 T6749 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
   [junit4]   2> 1425193 T6749 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1425194 T6749 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1425230 T6749 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1425393 T6749 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1425394 T6749 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 1425396 T6749 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 1425413 T6749 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1425416 T6749 oass.IndexSchem

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

dThread.run(ClientCnxn.java:994)
   [junit4]   2> 
   [junit4]   2> 8633576 T6665 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 38628
   [junit4]   2> 8633575 T6747 oaz.ClientCnxn$SendThread.run WARN Unexpected exception java.lang.InterruptedException: sleep interrupted
   [junit4]   2> 	at java.lang.Thread.sleep(Native Method)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:994)
   [junit4]   2> 
   [junit4]   2> 8633577 T6665 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
   [junit4]   2> 8633578 T6665 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:42443 42443
   [junit4]   2> 8634421 T6665 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> 7223109 T6664 ccr.ThreadLeakControl.tryToInterruptAll SEVERE There are still zombie threads that couldn't be terminated:
   [junit4]   2> 	   1) Thread[id=6665, name=SUITE-ReplicationFactorTest-seed#[C8E31AF8470B2BB5]-worker, state=RUNNABLE, group=TGRP-ReplicationFactorTest]
   [junit4]   2> 	        at java.io.UnixFileSystem.canonicalize0(Native Method)
   [junit4]   2> 	        at java.io.UnixFileSystem.canonicalize(UnixFileSystem.java:172)
   [junit4]   2> 	        at java.io.File.getCanonicalPath(File.java:618)
   [junit4]   2> 	        at java.io.FilePermission$1.run(FilePermission.java:215)
   [junit4]   2> 	        at java.io.FilePermission$1.run(FilePermission.java:203)
   [junit4]   2> 	        at java.security.AccessController.doPrivileged(Native Method)
   [junit4]   2> 	        at java.io.FilePermission.init(FilePermission.java:203)
   [junit4]   2> 	        at java.io.FilePermission.<init>(FilePermission.java:277)
   [junit4]   2> 	        at java.lang.SecurityManager.checkRead(SecurityManager.java:888)
   [junit4]   2> 	        at java.io.File.exists(File.java:814)
   [junit4]   2> 	        at org.apache.lucene.util.TestUtil.rm(TestUtil.java:124)
   [junit4]   2> 	        at org.apache.lucene.util.TestUtil.rm(TestUtil.java:126)
   [junit4]   2> 	        at org.apache.lucene.util.TestUtil.rm(TestUtil.java:126)
   [junit4]   2> 	        at org.apache.lucene.util.TestUtil.rm(TestUtil.java:126)
   [junit4]   2> 	        at org.apache.lucene.util.TestUtil.rm(TestUtil.java:126)
   [junit4]   2> 	        at org.apache.lucene.util.TestUtil.rm(TestUtil.java:126)
   [junit4]   2> 	        at org.apache.lucene.util.TestUtil.rm(TestUtil.java:110)
   [junit4]   2> 	        at org.apache.lucene.util.LuceneTestCase$TemporaryFilesCleanupRule.afterAlways(LuceneTestCase.java:2618)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.TestRuleAdapter$1.afterAlways(TestRuleAdapter.java:31)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:43)
   [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> NOTE: test params are: codec=Lucene46: {_version_=MockFixedIntBlock(blockSize=993), multiDefault=Pulsing41(freqCutoff=12 minBlockSize=52 maxBlockSize=147), a_t=Pulsing41(freqCutoff=12 minBlockSize=52 maxBlockSize=147), intDefault=MockFixedIntBlock(blockSize=993), range_facet_sl=PostingsFormat(name=Lucene41WithOrds), range_facet_si=Pulsing41(freqCutoff=12 minBlockSize=52 maxBlockSize=147), id=PostingsFormat(name=Lucene41WithOrds), text=PostingsFormat(name=Memory doPackFST= false), range_facet_l=Pulsing41(freqCutoff=12 minBlockSize=52 maxBlockSize=147), timestamp=Pulsing41(freqCutoff=12 minBlockSize=52 maxBlockSize=147)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=ru_RU, timezone=Asia/Ulaanbaatar
   [junit4]   2> NOTE: Linux 3.8.0-39-generic i386/Oracle Corporation 1.8.0_20-ea (32-bit)/cpus=8,threads=2,free=108530256,total=194285568
   [junit4]   2> NOTE: All tests run in this JVM: [QueryElevationComponentTest, DistributedQueryElevationComponentTest, TestBM25SimilarityFactory, FastVectorHighlighterTest, SolrTestCaseJ4Test, TestBlendedInfixSuggestions, UUIDFieldTest, TestRandomMergePolicy, TestRandomDVFaceting, TestSchemaSimilarityResource, SampleTest, BadComponentTest, TestGroupingSearch, IndexSchemaTest, TestFieldSortValues, TestPostingsSolrHighlighter, AnalysisErrorHandlingTest, SliceStateUpdateTest, TestManagedSchema, DocExpirationUpdateProcessorFactoryTest, UpdateRequestProcessorFactoryTest, ShardRoutingTest, LoggingHandlerTest, MoreLikeThisHandlerTest, DocValuesMissingTest, TestCloudManagedSchema, TestRemoteStreaming, TriLevelCompositeIdRoutingTest, EchoParamsTest, TestPerFieldSimilarity, DOMUtilTest, TestManagedResourceStorage, CircularListTest, OverseerTest, TestRealTimeGet, TestDocSet, TestSearcherReuse, DeleteShardTest, TestJoin, FileBasedSpellCheckerTest, DirectUpdateHandlerOptimizeTest, StatelessScriptUpdateProcessorFactoryTest, CoreMergeIndexesAdminHandlerTest, SchemaVersionSpecificBehaviorTest, PolyFieldTest, LukeRequestHandlerTest, UnloadDistributedZkTest, AutoCommitTest, TestCollationFieldDocValues, SolrCoreTest, LegacyHTMLStripCharFilterTest, TermVectorComponentTest, WordBreakSolrSpellCheckerTest, TestSuggestSpellingConverter, BinaryUpdateRequestHandlerTest, BasicDistributedZkTest, TestJmxMonitoredMap, TestLMDirichletSimilarityFactory, TestMiniSolrCloudCluster, QueryParsingTest, HdfsBasicDistributedZkTest, TestRestManager, SliceStateTest, TestSolrXMLSerializer, CoreAdminHandlerTest, CSVRequestHandlerTest, BlockCacheTest, SolrIndexSplitterTest, DistribCursorPagingTest, TestFunctionQuery, SuggesterFSTTest, TestLuceneMatchVersion, TestNonDefinedSimilarityFactory, SSLMigrationTest, HttpPartitionTest, SoftAutoCommitTest, TestManagedSchemaFieldResource, HdfsBasicDistributedZk2Test, AsyncMigrateRouteKeyTest, TestFieldTypeResource, TestCursorMarkWithoutUniqueKey, TestExceedMaxTermLength, RecoveryZkTest, BasicFunctionalityTest, ResourceLoaderTest, AnalysisAfterCoreReloadTest, TestSolrIndexConfig, TestReversedWildcardFilterFactory, TestBadConfig, ShowFileRequestHandlerTest, TestSolrXmlPersistor, TestElisionMultitermQuery, URLClassifyProcessorTest, QueryEqualityTest, DistributedSpellCheckComponentTest, CachingDirectoryFactoryTest, SyncSliceTest, TestReplicationHandler, ZkSolrClientTest, ShardRoutingCustomTest, TestDistributedSearch, TermVectorComponentDistributedTest, TestMultiCoreConfBootstrap, TestReload, TestStressVersions, SimpleFacetsTest, PeerSyncTest, TestFiltering, SortByFunctionTest, TestSolrDeletionPolicy1, XsltUpdateRequestHandlerTest, TestSurroundQueryParser, PrimitiveFieldTypeTest, TermsComponentTest, DocumentBuilderTest, RequiredFieldsTest, IndexSchemaRuntimeFieldTest, TestCollationField, ReturnFieldsTest, TestCSVResponseWriter, UniqFieldsUpdateProcessorFactoryTest, TestPartialUpdateDeduplication, TestComponentsName, SearchHandlerTest, HighlighterConfigTest, TestQuerySenderListener, AlternateDirectoryTest, TestQuerySenderNoQuery, ResponseLogComponentTest, TestStressRecovery, TestSystemIdResolver, DateFieldTest, RAMDirectoryFactoryTest, ClusterStateTest, TestSolrJ, TestLRUCache, TestDocumentBuilder, ZkNodePropsTest, SystemInfoHandlerTest, FileUtilsTest, TestRTGBase, CursorPagingTest, TestCollationKeyRangeQueries, AliasIntegrationTest, DeleteInactiveReplicaTest, DeleteReplicaTest, MigrateRouteKeyTest, ReplicationFactorTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=ReplicationFactorTest -Dtests.seed=C8E31AF8470B2BB5 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ru_RU -Dtests.timezone=Asia/Ulaanbaatar -Dtests.file.encoding=UTF-8
   [junit4] ERROR   0.00s J0 | ReplicationFactorTest (suite) <<<
   [junit4]    > Throwable #1: java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([C8E31AF8470B2BB5]:0)
   [junit4] Completed on J0 in 7223.17s, 1 test, 2 errors <<< FAILURES!

[...truncated 11 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:467: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:447: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:45: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/extra-targets.xml:37: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:189: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:496: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1297: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:921: There were test failures: 396 suites, 1640 tests, 1 suite-level error, 1 error, 36 ignored (15 assumptions)

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



Mime
View raw message