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 (64bit/jdk1.8.0_11) - Build # 10791 - Failure!
Date Mon, 28 Jul 2014 12:48:50 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/10791/
Java: 64bit/jdk1.8.0_11 -XX:-UseCompressedOops -XX:+UseG1GC

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




Build Log:
[...truncated 12526 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-7294C68DF5EDB42E-001/init-core-data-001
   [junit4]   2> 2385237 T6663 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 2385239 T6663 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> 2385240 T6663 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 2385241 T6664 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 2385341 T6663 oasc.ZkTestServer.run start zk server on port:40123
   [junit4]   2> 2385342 T6663 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2385344 T6670 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@643c6970 name:ZooKeeperConnection Watcher:127.0.0.1:40123 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2385345 T6663 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2385345 T6663 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 2385350 T6663 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2385351 T6672 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@68c0e675 name:ZooKeeperConnection Watcher:127.0.0.1:40123/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2385351 T6663 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2385352 T6663 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 2385354 T6663 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 2385355 T6663 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 2385357 T6663 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 2385359 T6663 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> 2385359 T6663 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 2385363 T6663 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> 2385364 T6663 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 2385367 T6663 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> 2385368 T6663 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 2385371 T6663 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> 2385372 T6663 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 2385375 T6663 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> 2385376 T6663 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 2385379 T6663 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> 2385379 T6663 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 2385382 T6663 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> 2385383 T6663 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 2385386 T6663 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> 2385386 T6663 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 2385388 T6663 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> 2385389 T6663 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 2385391 T6663 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> 2385392 T6663 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 2385395 T6663 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> 2385395 T6663 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 2385776 T6663 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 2385804 T6663 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:44749
   [junit4]   2> 2385805 T6663 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 2385805 T6663 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2385805 T6663 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-002
   [junit4]   2> 2385806 T6663 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-002/'
   [junit4]   2> 2385820 T6663 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-7294C68DF5EDB42E-001/tempDir-002/solr.xml
   [junit4]   2> 2385829 T6663 oasc.CoreContainer.<init> New CoreContainer 165741483
   [junit4]   2> 2385829 T6663 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-002/]
   [junit4]   2> 2385846 T6663 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 2385847 T6663 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 2385847 T6663 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 2385847 T6663 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 2385847 T6663 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 2385848 T6663 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 2385848 T6663 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 2385848 T6663 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 2385848 T6663 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 2385849 T6663 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
   [junit4]   2> 2385849 T6663 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 2385849 T6663 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 2385850 T6663 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 2385850 T6663 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:40123/solr
   [junit4]   2> 2385850 T6663 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2385851 T6663 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2385852 T6683 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@279d3396 name:ZooKeeperConnection Watcher:127.0.0.1:40123 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2385853 T6663 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2385855 T6663 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2385856 T6685 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@31c5e694 name:ZooKeeperConnection Watcher:127.0.0.1:40123/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2385856 T6663 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2385857 T6663 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 2385859 T6663 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 2385860 T6663 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 2385862 T6663 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 2385863 T6663 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 2385865 T6663 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 2385866 T6663 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:47315_
   [junit4]   2> 2385866 T6663 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:47315_
   [junit4]   2> 2385868 T6663 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 2385869 T6663 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 2385871 T6663 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:47315_
   [junit4]   2> 2385871 T6663 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 2385873 T6663 oasc.Overseer.start Overseer (id=92179299345235971-127.0.0.1:47315_-n_0000000000) starting
   [junit4]   2> 2385875 T6663 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 2385881 T6687 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 2385881 T6663 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 2385884 T6663 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 2385885 T6663 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2385887 T6686 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 2385889 T6688 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 2385889 T6688 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2385890 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2385890 T6688 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 2385891 T6686 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2385891 T6686 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:47315",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:47315_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 2385891 T6686 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 2385891 T6686 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 2385892 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2385893 T6685 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> 2386890 T6688 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 2386891 T6688 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 2386892 T6688 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 2386892 T6688 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 2386893 T6688 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 2386893 T6688 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-002/collection1/'
   [junit4]   2> 2386894 T6688 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-002/collection1/lib/.svn/' to classloader
   [junit4]   2> 2386894 T6688 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-002/collection1/lib/classes/' to classloader
   [junit4]   2> 2386894 T6688 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-002/collection1/lib/README' to classloader
   [junit4]   2> 2386924 T6688 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_10
   [junit4]   2> 2386938 T6688 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 2386939 T6688 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 2386946 T6688 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 2387079 T6688 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 2387079 T6688 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 2387079 T6688 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 2387084 T6688 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2387085 T6688 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2387094 T6688 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2387096 T6688 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2387098 T6688 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2387099 T6688 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2387099 T6688 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2387099 T6688 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2387100 T6688 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2387100 T6688 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2387100 T6688 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 2387100 T6688 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 2387101 T6688 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-002/collection1/, dataDir=./solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-001/control/data/
   [junit4]   2> 2387101 T6688 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@71c0bc9c
   [junit4]   2> 2387101 T6688 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-001/control/data
   [junit4]   2> 2387102 T6688 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-001/control/data/index/
   [junit4]   2> 2387102 T6688 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-001/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 2387102 T6688 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-001/control/data/index
   [junit4]   2> 2387102 T6688 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=50, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4892051854128152]
   [junit4]   2> 2387103 T6688 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@50cfd858 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@55caac36),segFN=segments_1,generation=1}
   [junit4]   2> 2387103 T6688 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2387106 T6688 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 2387106 T6688 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 2387106 T6688 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 2387106 T6688 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2387107 T6688 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2387107 T6688 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 2387107 T6688 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2387107 T6688 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2387108 T6688 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 2387108 T6688 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 2387108 T6688 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 2387108 T6688 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 2387109 T6688 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 2387109 T6688 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 2387109 T6688 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 2387110 T6688 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 2387111 T6688 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2387113 T6688 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 2387113 T6688 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 2387114 T6688 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=33, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 2387114 T6688 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@50cfd858 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@55caac36),segFN=segments_1,generation=1}
   [junit4]   2> 2387114 T6688 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2387114 T6688 oass.SolrIndexSearcher.<init> Opening Searcher@f87f317[collection1] main
   [junit4]   2> 2387115 T6688 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 2387116 T6688 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 2387116 T6688 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 2387116 T6688 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 2387117 T6688 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 2387117 T6688 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2387117 T6688 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 2387117 T6688 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2387118 T6688 oascc.SolrZkClient.makePath makePath: /configs/conf1/_rest_managed.json
   [junit4]   2> 2387121 T6688 oasr.ManagedResourceStorage$ZooKeeperStorageIO$1.close Wrote 38 bytes to new znode /configs/conf1/_rest_managed.json
   [junit4]   2> 2387121 T6688 oasr.ManagedResourceStorage$JsonStorage.store Saved JSON object to path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2387121 T6688 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 2387123 T6689 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f87f317[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 2387124 T6688 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 2387125 T6692 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:47315 collection:control_collection shard:shard1
   [junit4]   2> 2387126 T6663 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 2387126 T6663 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 2387126 T6692 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 2387132 T6663 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2387132 T6692 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 2387132 T6695 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@193ce834 name:ZooKeeperConnection Watcher:127.0.0.1:40123/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2387133 T6663 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2387134 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2387134 T6692 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 2387134 T6692 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 2387134 T6663 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2387135 T6686 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> ASYNC  NEW_CORE C1945 name=collection1 org.apache.solr.core.SolrCore@cb850b3 url=http://127.0.0.1:47315/collection1 node=127.0.0.1:47315_ C1945_STATE=coll:control_collection core:collection1 props:{state=down, base_url=http://127.0.0.1:47315, core=collection1, node_name=127.0.0.1:47315_}
   [junit4]   2> 2387135 T6692 C1945 P47315 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:47315/collection1/
   [junit4]   2> 2387136 T6692 C1945 P47315 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 2387136 T6692 C1945 P47315 oasc.SyncStrategy.syncToMe http://127.0.0.1:47315/collection1/ has no replicas
   [junit4]   2> 2387136 T6692 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:47315/collection1/ shard1
   [junit4]   2> 2387136 T6692 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 2387137 T6663 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 2387137 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2387140 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2387142 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2387243 T6685 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> 2387243 T6695 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> 2387291 T6692 oasc.ZkController.register We are http://127.0.0.1:47315/collection1/ and leader is http://127.0.0.1:47315/collection1/
   [junit4]   2> 2387291 T6692 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:47315
   [junit4]   2> 2387291 T6692 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 2387291 T6692 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 2387291 T6692 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2387292 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2387293 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2387293 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2387293 T6692 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2387294 T6686 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2387294 T6686 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:47315",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:47315_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 2387295 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2387397 T6685 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> 2387397 T6695 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> 2387423 T6663 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 2387424 T6663 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 2387425 T6663 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:47542
   [junit4]   2> 2387426 T6663 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 2387426 T6663 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2387426 T6663 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-003
   [junit4]   2> 2387427 T6663 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-003/'
   [junit4]   2> 2387441 T6663 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-7294C68DF5EDB42E-001/tempDir-003/solr.xml
   [junit4]   2> 2387450 T6663 oasc.CoreContainer.<init> New CoreContainer 2058059203
   [junit4]   2> 2387451 T6663 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-003/]
   [junit4]   2> 2387451 T6663 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 2387451 T6663 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 2387452 T6663 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 2387452 T6663 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 2387452 T6663 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 2387452 T6663 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 2387453 T6663 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 2387453 T6663 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 2387453 T6663 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 2387453 T6663 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
   [junit4]   2> 2387454 T6663 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 2387454 T6663 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 2387454 T6663 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 2387454 T6663 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:40123/solr
   [junit4]   2> 2387455 T6663 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2387455 T6663 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2387456 T6706 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7e5ca2da name:ZooKeeperConnection Watcher:127.0.0.1:40123 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2387457 T6663 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2387458 T6663 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2387459 T6708 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@24c4109f name:ZooKeeperConnection Watcher:127.0.0.1:40123/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2387459 T6663 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2387466 T6663 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2388469 T6663 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36790_
   [junit4]   2> 2388469 T6663 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36790_
   [junit4]   2> 2388471 T6708 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 2388472 T6695 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 2388471 T6685 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 2388476 T6709 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 2388476 T6709 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2388477 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2388477 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2388478 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2388477 T6709 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 2388479 T6686 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2388480 T6686 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:36790",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:36790_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 2388481 T6686 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
   [junit4]   2> 2388481 T6686 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 2388483 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2388585 T6708 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> 2388585 T6695 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> 2388587 T6685 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> 2389478 T6709 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 2389479 T6709 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 2389480 T6709 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 2389480 T6709 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 2389482 T6709 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 2389482 T6709 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-003/collection1/'
   [junit4]   2> 2389483 T6709 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-003/collection1/lib/.svn/' to classloader
   [junit4]   2> 2389484 T6709 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-003/collection1/lib/classes/' to classloader
   [junit4]   2> 2389484 T6709 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-003/collection1/lib/README' to classloader
   [junit4]   2> 2389507 T6709 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_10
   [junit4]   2> 2389518 T6709 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 2389519 T6709 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 2389524 T6709 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 2389643 T6709 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 2389644 T6709 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 2389645 T6709 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 2389649 T6709 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2389650 T6709 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2389656 T6709 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2389658 T6709 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2389659 T6709 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2389660 T6709 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2389660 T6709 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2389660 T6709 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2389661 T6709 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2389661 T6709 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2389661 T6709 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 2389662 T6709 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 2389662 T6709 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-003/collection1/, dataDir=./solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-001/jetty1/
   [junit4]   2> 2389662 T6709 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@71c0bc9c
   [junit4]   2> 2389662 T6709 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-001/jetty1
   [junit4]   2> 2389663 T6709 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-001/jetty1/index/
   [junit4]   2> 2389663 T6709 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-001/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 2389663 T6709 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-001/jetty1/index
   [junit4]   2> 2389663 T6709 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=50, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4892051854128152]
   [junit4]   2> 2389664 T6709 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@420fae39 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7517b063),segFN=segments_1,generation=1}
   [junit4]   2> 2389664 T6709 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2389666 T6709 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 2389666 T6709 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 2389666 T6709 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 2389667 T6709 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2389667 T6709 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2389667 T6709 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 2389667 T6709 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2389667 T6709 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2389668 T6709 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 2389668 T6709 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 2389668 T6709 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 2389668 T6709 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 2389669 T6709 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 2389669 T6709 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 2389669 T6709 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 2389669 T6709 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 2389671 T6709 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2389672 T6709 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 2389672 T6709 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 2389673 T6709 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=33, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 2389673 T6709 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@420fae39 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7517b063),segFN=segments_1,generation=1}
   [junit4]   2> 2389673 T6709 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2389674 T6709 oass.SolrIndexSearcher.<init> Opening Searcher@5f9acfcf[collection1] main
   [junit4]   2> 2389674 T6709 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 2389674 T6709 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 2389675 T6709 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 2389675 T6709 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 2389675 T6709 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 2389675 T6709 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2389676 T6709 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json
   [junit4]   2> 2389676 T6709 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2389676 T6709 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed
   [junit4]   2> 2389676 T6709 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 2389678 T6710 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5f9acfcf[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 2389679 T6709 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 2389679 T6713 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:36790 collection:collection1 shard:shard2
   [junit4]   2> 2389680 T6663 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 2389680 T6663 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 2389680 T6713 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 2389683 T6713 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 2389684 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2389684 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2389684 T6713 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 2389684 T6713 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 2389684 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> ASYNC  NEW_CORE C1946 name=collection1 org.apache.solr.core.SolrCore@4e9a2d92 url=http://127.0.0.1:36790/collection1 node=127.0.0.1:36790_ C1946_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:36790, core=collection1, node_name=127.0.0.1:36790_}
   [junit4]   2> 2389685 T6713 C1946 P36790 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:36790/collection1/
   [junit4]   2> 2389685 T6686 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2389685 T6713 C1946 P36790 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 2389686 T6713 C1946 P36790 oasc.SyncStrategy.syncToMe http://127.0.0.1:36790/collection1/ has no replicas
   [junit4]   2> 2389686 T6713 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:36790/collection1/ shard2
   [junit4]   2> 2389686 T6713 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 2389687 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2389688 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2389690 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2389791 T6708 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> 2389791 T6695 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> 2389791 T6685 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> 2389839 T6713 oasc.ZkController.register We are http://127.0.0.1:36790/collection1/ and leader is http://127.0.0.1:36790/collection1/
   [junit4]   2> 2389839 T6713 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:36790
   [junit4]   2> 2389839 T6713 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 2389840 T6713 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 2389840 T6713 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2389841 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2389841 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2389841 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2389841 T6713 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2389842 T6686 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2389842 T6686 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:36790",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:36790_",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 2389844 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2389945 T6685 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> 2389945 T6695 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> 2389945 T6708 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> 2389976 T6663 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 2389977 T6663 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 2389980 T6663 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:48194
   [junit4]   2> 2389981 T6663 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 2389981 T6663 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2389981 T6663 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-004
   [junit4]   2> 2389982 T6663 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-004/'
   [junit4]   2> 2389999 T6663 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-7294C68DF5EDB42E-001/tempDir-004/solr.xml
   [junit4]   2> 2390010 T6663 oasc.CoreContainer.<init> New CoreContainer 541897779
   [junit4]   2> 2390010 T6663 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-004/]
   [junit4]   2> 2390011 T6663 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 2390011 T6663 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 2390012 T6663 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 2390012 T6663 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 2390012 T6663 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 2390012 T6663 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 2390013 T6663 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 2390013 T6663 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 2390013 T6663 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 2390013 T6663 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
   [junit4]   2> 2390014 T6663 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 2390014 T6663 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 2390014 T6663 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 2390014 T6663 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:40123/solr
   [junit4]   2> 2390015 T6663 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2390015 T6663 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2390017 T6725 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3838b9c7 name:ZooKeeperConnection Watcher:127.0.0.1:40123 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2390018 T6663 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2390020 T6663 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2390021 T6727 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c25a199 name:ZooKeeperConnection Watcher:127.0.0.1:40123/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2390021 T6663 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2390028 T6663 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2391030 T6663 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36149_
   [junit4]   2> 2391032 T6663 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36149_
   [junit4]   2> 2391034 T6695 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 2391034 T6685 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 2391034 T6727 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 2391034 T6708 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 2391041 T6728 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 2391041 T6728 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2391042 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2391042 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2391043 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2391042 T6728 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 2391044 T6686 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2391045 T6686 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:36149",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:36149_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 2391045 T6686 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 2391046 T6686 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 2391047 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2391148 T6708 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> 2391149 T6727 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> 2391149 T6685 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> 2391148 T6695 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> 2392044 T6728 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 2392044 T6728 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 2392044 T6728 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 2392044 T6728 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 2392045 T6728 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 2392045 T6728 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-004/collection1/'
   [junit4]   2> 2392046 T6728 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-004/collection1/lib/.svn/' to classloader
   [junit4]   2> 2392046 T6728 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-004/collection1/lib/classes/' to classloader
   [junit4]   2> 2392046 T6728 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-004/collection1/lib/README' to classloader
   [junit4]   2> 2392070 T6728 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_10
   [junit4]   2> 2392081 T6728 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 2392082 T6728 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 2392101 T6728 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 2392210 T6728 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 2392211 T6728 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 2392212 T6728 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
   [junit4]   2> 2392216 T6728 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 2392217 T6728 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 2392224 T6728 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2392226 T6728 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 2392227 T6728 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2392228 T6728 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2392228 T6728 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2392228 T6728 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
   [junit4]   2> 2392229 T6728 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
   [junit4]   2> 2392229 T6728 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
   [junit4]   2> 2392229 T6728 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 2392229 T6728 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 2392229 T6728 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-004/collection1/, dataDir=./solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-001/jetty2/
   [junit4]   2> 2392230 T6728 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@71c0bc9c
   [junit4]   2> 2392230 T6728 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-001/jetty2
   [junit4]   2> 2392230 T6728 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-001/jetty2/index/
   [junit4]   2> 2392230 T6728 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-001/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 2392231 T6728 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-001/jetty2/index
   [junit4]   2> 2392231 T6728 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=50, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4892051854128152]
   [junit4]   2> 2392231 T6728 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@37c6d141 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7366748),segFN=segments_1,generation=1}
   [junit4]   2> 2392232 T6728 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2392234 T6728 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 2392234 T6728 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 2392234 T6728 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 2392234 T6728 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2392234 T6728 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 2392235 T6728 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 2392235 T6728 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2392235 T6728 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 2392235 T6728 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 2392236 T6728 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 2392236 T6728 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 2392236 T6728 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 2392236 T6728 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 2392237 T6728 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 2392237 T6728 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 2392237 T6728 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 2392239 T6728 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 2392240 T6728 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 2392240 T6728 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 2392241 T6728 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=33, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
   [junit4]   2> 2392241 T6728 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@37c6d141 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@7366748),segFN=segments_1,generation=1}
   [junit4]   2> 2392241 T6728 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 2392241 T6728 oass.SolrIndexSearcher.<init> Opening Searcher@5111bd92[collection1] main
   [junit4]   2> 2392242 T6728 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 2392242 T6728 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 2392242 T6728 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 2392243 T6728 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 2392243 T6728 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 2392243 T6728 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2392243 T6728 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream Read 38 bytes from znode /configs/conf1/_rest_managed.json
   [junit4]   2> 2392244 T6728 oasr.ManagedResourceStorage.load Loaded LinkedHashMap at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 2392244 T6728 oasr.ManagedResource.reloadFromStorage Loaded initArgs {} for /rest/managed
   [junit4]   2> 2392244 T6728 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 2392258 T6729 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5111bd92[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 2392259 T6728 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 2392260 T6732 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:36149 collection:collection1 shard:shard3
   [junit4]   2> 2392261 T6663 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 2392261 T6663 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 2392261 T6732 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 2392264 T6732 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard3
   [junit4]   2> 2392265 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2392265 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2392265 T6732 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 2392266 T6732 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> 2392265 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> ASYNC  NEW_CORE C1947 name=collection1 org.apache.solr.core.SolrCore@21a6e9a5 url=http://127.0.0.1:36149/collection1 node=127.0.0.1:36149_ C1947_STATE=coll:collection1 core:collection1 props:{state=down, base_url=http://127.0.0.1:36149, core=collection1, node_name=127.0.0.1:36149_}
   [junit4]   2> 2392266 T6732 C1947 P36149 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:36149/collection1/
   [junit4]   2> 2392266 T6732 C1947 P36149 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 2392267 T6732 C1947 P36149 oasc.SyncStrategy.syncToMe http://127.0.0.1:36149/collection1/ has no replicas
   [junit4]   2> 2392267 T6732 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:36149/collection1/ shard3
   [junit4]   2> 2392267 T6686 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2392267 T6732 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
   [junit4]   2> 2392269 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2392270 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2392272 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2392373 T6695 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> 2392373 T6685 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> 2392373 T6708 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> 2392373 T6727 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> 2392421 T6732 oasc.ZkController.register We are http://127.0.0.1:36149/collection1/ and leader is http://127.0.0.1:36149/collection1/
   [junit4]   2> 2392421 T6732 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:36149
   [junit4]   2> 2392421 T6732 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 2392421 T6732 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 2392422 T6732 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2392423 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2392423 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2392423 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2392423 T6732 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2392424 T6686 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2392424 T6686 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:36149",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:36149_",
   [junit4]   2> 	  "shard":"shard3",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 2392425 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2392527 T6708 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> 2392527 T6727 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> 2392527 T6685 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> 2392527 T6695 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> 2392543 T6663 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
   [junit4]   2> 2392544 T6663 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 2392546 T6663 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:37335
   [junit4]   2> 2392546 T6663 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 2392547 T6663 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 2392547 T6663 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-005
   [junit4]   2> 2392547 T6663 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-005/'
   [junit4]   2> 2392562 T6663 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-7294C68DF5EDB42E-001/tempDir-005/solr.xml
   [junit4]   2> 2392572 T6663 oasc.CoreContainer.<init> New CoreContainer 252032628
   [junit4]   2> 2392572 T6663 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-005/]
   [junit4]   2> 2392572 T6663 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 2392573 T6663 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 2392573 T6663 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 2392573 T6663 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 2392573 T6663 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 2392574 T6663 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 2392574 T6663 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 2392574 T6663 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 2392574 T6663 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 2392575 T6663 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=false
   [junit4]   2> 2392575 T6663 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 2392575 T6663 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 2392576 T6663 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 2392576 T6663 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:40123/solr
   [junit4]   2> 2392576 T6663 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 2392577 T6663 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2392578 T6744 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@54e4c390 name:ZooKeeperConnection Watcher:127.0.0.1:40123 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2392578 T6663 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2392580 T6663 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 2392580 T6746 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@291ed2a2 name:ZooKeeperConnection Watcher:127.0.0.1:40123/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 2392581 T6663 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 2392584 T6663 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 2393586 T6663 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57659_
   [junit4]   2> 2393587 T6663 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57659_
   [junit4]   2> 2393589 T6695 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 2393589 T6708 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 2393589 T6685 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 2393589 T6727 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 2393589 T6746 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 2393592 T6747 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 2393592 T6747 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 2393593 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2393593 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2393593 T6747 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 2393593 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2393594 T6686 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 2393594 T6686 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:57659",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:57659_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 2393594 T6686 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 2393594 T6686 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 2393595 T6685 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 2393697 T6708 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> 2393697 T6746 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> 2393697 T6727 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> 2393697 T6695 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> 2393697 T6685 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> 2394593 T6747 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 2394593 T6747 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 2394594 T6747 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 2394594 T6747 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 2394595 T6747 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 2394595 T6747 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-005/collection1/'
   [junit4]   2> 2394596 T6747 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-005/collection1/lib/.svn/' to classloader
   [junit4]   2> 2394596 T6747 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-005/collection1/lib/classes/' to classloader
   [junit4]   2> 2394597 T6747 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/solr.cloud.ReplicationFactorTest-7294C68DF5EDB42E-001/tempDir-005/collection1/lib/README' to classloader
   [junit4]   2> 2394617 T6747 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_10
   [junit4]   2> 2394627 T6747 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 2394628 T6747 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 2394632 T6747 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 2394760 T6747 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
   [junit4]   2> 2394761 T6747 oas

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

nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:569)
   [junit4]   2> 	        at org.eclipse.jetty.io.nio.SelectorManager$1.run(SelectorManager.java:290)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 	  21) Thread[id=6718, name=qtp1274855277-6718 Acceptor0 SelectChannelConnector@127.0.0.1:48194, state=RUNNABLE, group=TGRP-ReplicationFactorTest]
   [junit4]   2> 	        at org.eclipse.jetty.server.nio.SelectChannelConnector.getConnection(SelectChannelConnector.java:160)
   [junit4]   2> 	        at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:934)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 	  22) Thread[id=6715, name=HashSessionScavenger-211, state=TIMED_WAITING, group=TGRP-ReplicationFactorTest]
   [junit4]   2> 	        at java.lang.Object.wait(Native Method)
   [junit4]   2> 	        at java.util.TimerThread.mainLoop(Timer.java:552)
   [junit4]   2> 	        at java.util.TimerThread.run(Timer.java:505)
   [junit4]   2> 	  23) Thread[id=6789, name=searcherExecutor-3763-thread-1, state=WAITING, group=TGRP-ReplicationFactorTest]
   [junit4]   2> 	        at sun.misc.Unsafe.park(Native Method)
   [junit4]   2> 	        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
   [junit4]   2> 	        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
   [junit4]   2> 	        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 	  24) Thread[id=6735, name=qtp514788331-6735 Selector0, state=RUNNABLE, group=TGRP-ReplicationFactorTest]
   [junit4]   2> 	        at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
   [junit4]   2> 	        at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
   [junit4]   2> 	        at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
   [junit4]   2> 	        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
   [junit4]   2> 	        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:97)
   [junit4]   2> 	        at org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:569)
   [junit4]   2> 	        at org.eclipse.jetty.io.nio.SelectorManager$1.run(SelectorManager.java:290)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 	  25) Thread[id=6745, name=TEST-ReplicationFactorTest.testDistribSearch-seed#[7294C68DF5EDB42E]-SendThread(127.0.0.1:40123), state=TIMED_WAITING, group=TGRP-ReplicationFactorTest]
   [junit4]   2> 	        at java.lang.Thread.sleep(Native Method)
   [junit4]   2> 	        at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:994)
   [junit4]   2> NOTE: test params are: codec=FastDecompressionCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=FAST_DECOMPRESSION, chunkSize=286), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=FAST_DECOMPRESSION, chunkSize=286)), sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=bg, timezone=America/Sitka
   [junit4]   2> NOTE: Linux 3.13.0-32-generic amd64/Oracle Corporation 1.8.0_11 (64-bit)/cpus=8,threads=30,free=188264408,total=536870912
   [junit4]   2> NOTE: All tests run in this JVM: [BasicFunctionalityTest, ResponseLogComponentTest, TestUtils, TestReloadAndDeleteDocs, StatelessScriptUpdateProcessorFactoryTest, TestInitQParser, TestSolrXMLSerializer, DistribCursorPagingTest, TestNonNRTOpen, TestSolrIndexConfig, SolrCoreCheckLockOnStartupTest, BlockCacheTest, AsyncMigrateRouteKeyTest, TestManagedSchemaFieldResource, StressHdfsTest, TestFieldTypeCollectionResource, TestNRTOpen, FastVectorHighlighterTest, TestDFRSimilarityFactory, TestCollectionAPI, ChangedSchemaMergeTest, TestSurroundQueryParser, ClusterStateTest, TestFuzzyAnalyzedSuggestions, IndexBasedSpellCheckerTest, AssignTest, TestManagedResource, CursorMarkTest, TestSolrDeletionPolicy1, BadComponentTest, SignatureUpdateProcessorFactoryTest, EchoParamsTest, TestClassNameShortening, HighlighterConfigTest, BJQParserTest, TestSort, SuggestComponentTest, TestSolrXml, SimpleFacetsTest, TestWordDelimiterFilterFactory, TestComponentsName, ClusterStateUpdateTest, JSONWriterTest, WordBreakSolrSpellCheckerTest, TestExpandComponent, SolrCmdDistributorTest, UUIDFieldTest, MBeansHandlerTest, SliceStateTest, TestSolr4Spatial2, TestAnalyzeInfixSuggestions, DeleteShardTest, ExternalFileFieldSortTest, MergeStrategyTest, TestReplicationHandlerBackup, TestHighFrequencyDictionaryFactory, OpenExchangeRatesOrgProviderTest, TestMaxScoreQueryParser, TestOverriddenPrefixQueryForCustomFieldType, TestReRankQParserPlugin, TestSchemaSimilarityResource, TestChildDocTransformer, TestSolrCoreProperties, HighlighterTest, PluginInfoTest, PrimUtilsTest, UpdateParamsTest, TestFaceting, TestConfig, TestFieldSortValues, MoreLikeThisHandlerTest, TestCursorMarkWithoutUniqueKey, SpellPossibilityIteratorTest, TestDistributedMissingSort, TestBlendedInfixSuggestions, SolrIndexSplitterTest, CoreMergeIndexesAdminHandlerTest, RemoteQueryErrorTest, TestReplicationHandler, TestDocSet, DocumentAnalysisRequestHandlerTest, TestTrie, BasicDistributedZkTest, CustomCollectionTest, MinimalSchemaTest, PathHierarchyTokenizerFactoryTest, CoreAdminHandlerTest, DocumentBuilderTest, PreAnalyzedUpdateProcessorTest, PingRequestHandlerTest, TestLuceneMatchVersion, FieldMutatingUpdateProcessorTest, RequiredFieldsTest, TestCloudSchemaless, OverseerCollectionProcessorTest, HdfsRecoveryZkTest, TestIntervalFaceting, OverseerTest, DateFieldTest, TestAnalyzedSuggestions, BasicDistributedZk2Test, UnloadDistributedZkTest, SyncSliceTest, ShardRoutingTest, RecoveryZkTest, LeaderElectionTest, TestZkChroot, TestRandomDVFaceting, ZkCLITest, TestDistributedSearch, TestRecovery, TestHashPartitioner, DistributedSpellCheckComponentTest, ZkControllerTest, TestJoin, HardAutoCommitTest, DistributedTermsComponentTest, BadIndexSchemaTest, TestFunctionQuery, DirectUpdateHandlerTest, ShowFileRequestHandlerTest, CurrencyFieldOpenExchangeTest, DistributedQueryElevationComponentTest, TestAtomicUpdateErrorCases, DirectUpdateHandlerOptimizeTest, TestRemoteStreaming, TestReversedWildcardFilterFactory, PrimitiveFieldTypeTest, TestOmitPositions, TermsComponentTest, TestValueSourceCache, FieldAnalysisRequestHandlerTest, IndexSchemaRuntimeFieldTest, SolrPluginUtilsTest, TestJmxIntegration, QueryParsingTest, TestPartialUpdateDeduplication, CoreContainerCoreInitFailuresTest, TestLFUCache, TestQuerySenderListener, TestStressRecovery, PreAnalyzedFieldTest, TestSuggestSpellingConverter, SpellingQueryConverterTest, DOMUtilTest, RAMDirectoryFactoryTest, TestSolrJ, TestDocumentBuilder, ZkNodePropsTest, SystemInfoHandlerTest, CircularListTest, CursorPagingTest, DistributedIntervalFacetingTest, ConnectionManagerTest, DeleteInactiveReplicaTest, HttpPartitionTest, OverseerRolesTest, ReplicationFactorTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=ReplicationFactorTest -Dtests.seed=7294C68DF5EDB42E -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=bg -Dtests.timezone=America/Sitka -Dtests.file.encoding=US-ASCII
   [junit4] ERROR   0.00s J0 | ReplicationFactorTest (suite) <<<
   [junit4]    > Throwable #1: java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([7294C68DF5EDB42E]:0)
   [junit4] Completed on J0 in 7223.72s, 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:1299: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:923: There were test failures: 410 suites, 1702 tests, 1 suite-level error, 1 error, 38 ignored (17 assumptions)

Total time: 202 minutes 56 seconds
Build step 'Invoke Ant' marked build as failure
[description-setter] Description set: Java: 64bit/jdk1.8.0_11 -XX:-UseCompressedOops -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any



Mime
View raw message