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.7.0_60-ea-b14) - Build # 10072 - Failure!
Date Mon, 28 Apr 2014 17:44:17 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/10072/
Java: 64bit/jdk1.7.0_60-ea-b14 -XX:-UseCompressedOops -XX:+UseSerialGC

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

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

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


REGRESSION:  org.apache.solr.cloud.RecoveryZkTest.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([D32612A5C272D312]:0)




Build Log:
[...truncated 11783 lines...]
   [junit4] Suite: org.apache.solr.cloud.RecoveryZkTest
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/init-core-data-001
   [junit4]   2> 91348 T220 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
   [junit4]   2> 91349 T220 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 91353 T220 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> 91354 T220 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 91354 T221 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 91454 T220 oasc.ZkTestServer.run start zk server on port:47201
   [junit4]   2> 91455 T220 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 91576 T227 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@30257e02 name:ZooKeeperConnection Watcher:127.0.0.1:47201 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 91576 T220 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 91577 T220 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 91585 T220 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 91588 T229 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18d1b449 name:ZooKeeperConnection Watcher:127.0.0.1:47201/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 91588 T220 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 91589 T220 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 91597 T220 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 91603 T220 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 91609 T220 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 91615 T220 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 91616 T220 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 91627 T220 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/core/src/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
   [junit4]   2> 91627 T220 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 91635 T220 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 91636 T220 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 91641 T220 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 91642 T220 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 91648 T220 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 91649 T220 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 91656 T220 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 91656 T220 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 91663 T220 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 91663 T220 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 91670 T220 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 91671 T220 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 91677 T220 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 91678 T220 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 91684 T220 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 91685 T220 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 91692 T220 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 91693 T220 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 91703 T220 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 91706 T231 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5cc06b51 name:ZooKeeperConnection Watcher:127.0.0.1:47201/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 91706 T220 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 92003 T220 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 92149 T220 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 92152 T220 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:51382
   [junit4]   2> 92154 T220 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 92154 T220 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 92155 T220 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-002
   [junit4]   2> 92155 T220 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-002/'
   [junit4]   2> 92166 T220 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-002/solr.xml
   [junit4]   2> 92205 T220 oasc.CoreContainer.<init> New CoreContainer 436966452
   [junit4]   2> 92205 T220 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-002/]
   [junit4]   2> 92206 T220 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 92207 T220 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 92207 T220 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 92207 T220 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 92207 T220 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 92207 T220 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 92208 T220 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 92208 T220 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 92208 T220 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 92211 T220 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 92212 T220 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 92212 T220 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 92212 T220 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:47201/solr
   [junit4]   2> 92213 T220 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 92213 T220 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 92216 T242 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3ca6b2e9 name:ZooKeeperConnection Watcher:127.0.0.1:47201 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 92216 T220 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 92218 T220 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 92220 T244 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ec95f7d name:ZooKeeperConnection Watcher:127.0.0.1:47201/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 92220 T220 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 92222 T220 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 92225 T220 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 92228 T220 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 92231 T220 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 92235 T220 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 92239 T220 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 92240 T220 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51382_
   [junit4]   2> 92241 T220 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51382_
   [junit4]   2> 92245 T220 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 92248 T220 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 92255 T220 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:51382_
   [junit4]   2> 92255 T220 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 92258 T220 oasc.Overseer.start Overseer (id=91665190906429444-127.0.0.1:51382_-n_0000000000) starting
   [junit4]   2> 92261 T220 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 92273 T246 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 92274 T220 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 92274 T246 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes at 127.0.0.1:51382_
   [junit4]   2> 92278 T220 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 92281 T220 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 92287 T245 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 92290 T247 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 92291 T247 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 92293 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 92293 T247 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 92296 T245 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 92298 T245 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:51382",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:51382_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 92298 T245 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 92300 T245 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 92304 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 92305 T244 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> 93293 T247 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 93294 T247 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 93295 T247 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 93295 T247 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 93296 T247 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 93296 T247 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-002/collection1/'
   [junit4]   2> 93297 T247 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-002/collection1/lib/.svn/' to classloader
   [junit4]   2> 93297 T247 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-002/collection1/lib/classes/' to classloader
   [junit4]   2> 93297 T247 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-002/collection1/lib/README' to classloader
   [junit4]   2> 93329 T247 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_49
   [junit4]   2> 93362 T247 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 93364 T247 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 93372 T247 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 93626 T247 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 93628 T247 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 93630 T247 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 93634 T247 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 93673 T247 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 93673 T247 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 93673 T247 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-002/collection1/, dataDir=./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-001/control/data/
   [junit4]   2> 93673 T247 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7dd5a7f6
   [junit4]   2> 93674 T247 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-001/control/data
   [junit4]   2> 93674 T247 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-001/control/data/index/
   [junit4]   2> 93674 T247 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-001/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 93675 T247 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-001/control/data/index
   [junit4]   2> 93675 T247 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=31, maxMergeAtOnceExplicit=31, maxMergedSegmentMB=24.369140625, floorSegmentMB=0.564453125, forceMergeDeletesPctAllowed=6.49092092326198, segmentsPerTier=36.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 93676 T247 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@38883062 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6cb81e67),segFN=segments_1,generation=1}
   [junit4]   2> 93676 T247 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 93680 T247 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 93680 T247 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 93680 T247 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 93681 T247 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 93681 T247 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 93681 T247 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 93681 T247 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 93682 T247 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 93682 T247 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 93682 T247 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 93683 T247 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 93683 T247 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 93683 T247 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 93683 T247 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 93684 T247 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 93684 T247 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 93686 T247 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 93688 T247 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 93689 T247 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 93689 T247 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=28, maxMergeAtOnceExplicit=17, maxMergedSegmentMB=86.638671875, floorSegmentMB=0.59375, forceMergeDeletesPctAllowed=7.494133103986719, segmentsPerTier=28.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.13880062437600876
   [junit4]   2> 93690 T247 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@38883062 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6cb81e67),segFN=segments_1,generation=1}
   [junit4]   2> 93690 T247 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 93690 T247 oass.SolrIndexSearcher.<init> Opening Searcher@662c6d96[collection1] main
   [junit4]   2> 93690 T247 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 93692 T247 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 93692 T247 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 93692 T247 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 93692 T247 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 93693 T247 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 93694 T247 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 93694 T247 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 93694 T247 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 93694 T247 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 93697 T248 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@662c6d96[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 93699 T247 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 93700 T251 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:51382 collection:control_collection shard:shard1
   [junit4]   2> 93701 T220 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0
   [junit4]   2> 93701 T220 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 93702 T251 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 93707 T220 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 93709 T253 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7d7f7b1c name:ZooKeeperConnection Watcher:127.0.0.1:47201/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 93709 T251 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 93709 T220 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 93711 T220 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 93712 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 93713 T251 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 93713 T251 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C528 name=collection1 org.apache.solr.core.SolrCore@5a30f467 url=https://127.0.0.1:51382/collection1 node=127.0.0.1:51382_ C528_STATE=coll:control_collection core:collection1 props:{state=down, base_url=https://127.0.0.1:51382, core=collection1, node_name=127.0.0.1:51382_}
   [junit4]   2> 93713 T251 C528 P51382 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:51382/collection1/
   [junit4]   2> 93713 T251 C528 P51382 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 93713 T251 C528 P51382 oasc.SyncStrategy.syncToMe https://127.0.0.1:51382/collection1/ has no replicas
   [junit4]   2> 93714 T245 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 93714 T251 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:51382/collection1/ shard1
   [junit4]   2> 93714 T251 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 93716 T220 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 93718 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 93723 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 93727 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 93830 T253 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> 93830 T244 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> 93874 T251 oasc.ZkController.register We are https://127.0.0.1:51382/collection1/ and leader is https://127.0.0.1:51382/collection1/
   [junit4]   2> 93874 T251 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:51382
   [junit4]   2> 93874 T251 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 93874 T251 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 93875 T251 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 93878 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 93879 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 93879 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 93880 T251 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 93881 T245 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 93882 T245 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:51382",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:51382_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 93884 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 93987 T244 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> 93987 T253 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> 94075 T220 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 94078 T220 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 94084 T220 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 94088 T220 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:56751
   [junit4]   2> 94090 T220 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 94091 T220 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 94091 T220 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-003
   [junit4]   2> 94091 T220 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-003/'
   [junit4]   2> 94104 T220 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-003/solr.xml
   [junit4]   2> 94141 T220 oasc.CoreContainer.<init> New CoreContainer 2056501557
   [junit4]   2> 94141 T220 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-003/]
   [junit4]   2> 94142 T220 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 94143 T220 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 94143 T220 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 94143 T220 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 94143 T220 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 94144 T220 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 94144 T220 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 94144 T220 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 94144 T220 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 94147 T220 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 94147 T220 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 94148 T220 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 94148 T220 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:47201/solr
   [junit4]   2> 94148 T220 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 94149 T220 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 94150 T264 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@20dc0697 name:ZooKeeperConnection Watcher:127.0.0.1:47201 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 94151 T220 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 94153 T220 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 94154 T266 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@76f352a8 name:ZooKeeperConnection Watcher:127.0.0.1:47201/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 94155 T220 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 94162 T220 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 95166 T220 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56751_
   [junit4]   2> 95167 T220 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:56751_
   [junit4]   2> 95171 T253 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 95171 T266 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 95171 T244 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 95183 T267 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 95184 T267 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 95198 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 95198 T267 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 95198 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 95199 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 95201 T245 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 95202 T245 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:56751",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:56751_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 95203 T245 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 95203 T245 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 95222 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 95326 T244 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> 95326 T266 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> 95326 T253 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> 96199 T267 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 96199 T267 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 96200 T267 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 96200 T267 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 96201 T267 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 96202 T267 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-003/collection1/'
   [junit4]   2> 96202 T267 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-003/collection1/lib/.svn/' to classloader
   [junit4]   2> 96203 T267 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-003/collection1/lib/classes/' to classloader
   [junit4]   2> 96203 T267 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-003/collection1/lib/README' to classloader
   [junit4]   2> 96241 T267 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_49
   [junit4]   2> 96267 T267 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 96270 T267 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 96278 T267 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 96547 T267 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 96549 T267 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 96550 T267 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 96554 T267 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 96592 T267 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 96592 T267 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 96592 T267 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-003/collection1/, dataDir=./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-001/jetty1/
   [junit4]   2> 96592 T267 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7dd5a7f6
   [junit4]   2> 96593 T267 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-001/jetty1
   [junit4]   2> 96593 T267 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-001/jetty1/index/
   [junit4]   2> 96593 T267 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-001/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 96594 T267 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-001/jetty1/index
   [junit4]   2> 96594 T267 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=31, maxMergeAtOnceExplicit=31, maxMergedSegmentMB=24.369140625, floorSegmentMB=0.564453125, forceMergeDeletesPctAllowed=6.49092092326198, segmentsPerTier=36.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 96595 T267 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@26edc824 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@712d0924),segFN=segments_1,generation=1}
   [junit4]   2> 96595 T267 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 96600 T267 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 96600 T267 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 96600 T267 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 96601 T267 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 96601 T267 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 96601 T267 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 96601 T267 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 96602 T267 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 96602 T267 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 96602 T267 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 96603 T267 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 96603 T267 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 96603 T267 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 96604 T267 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 96604 T267 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 96604 T267 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 96607 T267 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 96609 T267 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 96609 T267 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 96610 T267 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=28, maxMergeAtOnceExplicit=17, maxMergedSegmentMB=86.638671875, floorSegmentMB=0.59375, forceMergeDeletesPctAllowed=7.494133103986719, segmentsPerTier=28.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.13880062437600876
   [junit4]   2> 96610 T267 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@26edc824 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@712d0924),segFN=segments_1,generation=1}
   [junit4]   2> 96610 T267 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 96611 T267 oass.SolrIndexSearcher.<init> Opening Searcher@3dc49080[collection1] main
   [junit4]   2> 96611 T267 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 96612 T267 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 96612 T267 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 96613 T267 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 96613 T267 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 96613 T267 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 96614 T267 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 96614 T267 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 96614 T267 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 96615 T267 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 96618 T268 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3dc49080[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 96620 T267 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 96621 T271 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:56751 collection:collection1 shard:shard1
   [junit4]   2> 96621 T220 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0
   [junit4]   2> 96622 T220 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 96625 T271 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 96634 T271 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 96636 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 96637 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 96637 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 96637 T271 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 96637 T271 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C529 name=collection1 org.apache.solr.core.SolrCore@2c11a31a url=https://127.0.0.1:56751/collection1 node=127.0.0.1:56751_ C529_STATE=coll:collection1 core:collection1 props:{state=down, base_url=https://127.0.0.1:56751, core=collection1, node_name=127.0.0.1:56751_}
   [junit4]   2> 96637 T271 C529 P56751 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:56751/collection1/
   [junit4]   2> 96638 T271 C529 P56751 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 96638 T271 C529 P56751 oasc.SyncStrategy.syncToMe https://127.0.0.1:56751/collection1/ has no replicas
   [junit4]   2> 96638 T271 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:56751/collection1/ shard1
   [junit4]   2> 96638 T271 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 96638 T245 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 96642 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 96645 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 96649 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 96763 T266 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> 96763 T253 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> 96763 T244 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> 96796 T271 oasc.ZkController.register We are https://127.0.0.1:56751/collection1/ and leader is https://127.0.0.1:56751/collection1/
   [junit4]   2> 96796 T271 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:56751
   [junit4]   2> 96797 T271 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 96797 T271 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 96797 T271 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 96799 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 96799 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 96799 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 96799 T271 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 96801 T245 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 96801 T245 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:56751",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:56751_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 96804 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 96898 T220 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 96899 T220 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 96906 T220 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 96906 T266 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> 96907 T253 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> 96906 T244 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> 96909 T220 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:51620
   [junit4]   2> 96911 T220 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 96912 T220 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 96912 T220 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-004
   [junit4]   2> 96912 T220 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-004/'
   [junit4]   2> 96923 T220 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-004/solr.xml
   [junit4]   2> 96960 T220 oasc.CoreContainer.<init> New CoreContainer 1944586304
   [junit4]   2> 96960 T220 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-004/]
   [junit4]   2> 96961 T220 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 96961 T220 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 96961 T220 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 96962 T220 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 96962 T220 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 96962 T220 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 96962 T220 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 96963 T220 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 96963 T220 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 96967 T220 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 96967 T220 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 96967 T220 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 96968 T220 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:47201/solr
   [junit4]   2> 96968 T220 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 96969 T220 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 96971 T282 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@bba39e1 name:ZooKeeperConnection Watcher:127.0.0.1:47201 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 96971 T220 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 96973 T220 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 96974 T284 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3c6537fb name:ZooKeeperConnection Watcher:127.0.0.1:47201/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 96975 T220 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 96982 T220 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 97985 T220 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51620_
   [junit4]   2> 97987 T220 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51620_
   [junit4]   2> 97990 T266 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 97991 T253 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 97991 T284 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 97991 T244 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 98002 T285 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 98002 T285 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 98003 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 98004 T285 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 98004 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 98004 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 98006 T245 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 98007 T245 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:51620",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:51620_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 98007 T245 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
   [junit4]   2> 98008 T245 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 98011 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 98114 T244 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> 98114 T284 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> 98114 T253 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> 98114 T266 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> 99004 T285 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 99005 T285 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 99006 T285 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 99006 T285 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 99009 T285 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 99009 T285 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-004/collection1/'
   [junit4]   2> 99010 T285 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-004/collection1/lib/.svn/' to classloader
   [junit4]   2> 99011 T285 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-004/collection1/lib/classes/' to classloader
   [junit4]   2> 99011 T285 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-004/collection1/lib/README' to classloader
   [junit4]   2> 99066 T285 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_49
   [junit4]   2> 99098 T285 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 99101 T285 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 99116 T285 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 99401 T285 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 99403 T285 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 99405 T285 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 99409 T285 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 99445 T285 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 99445 T285 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 99445 T285 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0/./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-004/collection1/, dataDir=./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-001/jetty2/
   [junit4]   2> 99445 T285 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7dd5a7f6
   [junit4]   2> 99446 T285 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-001/jetty2
   [junit4]   2> 99446 T285 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-001/jetty2/index/
   [junit4]   2> 99446 T285 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-001/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 99447 T285 oasc.CachingDirectoryFactory.get return new directory for ./solr.cloud.RecoveryZkTest-D32612A5C272D312-001/tempDir-001/jetty2/index
   [junit4]   2> 99447 T285 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=31, maxMergeAtOnceExplicit=31, maxMergedSegmentMB=24.369140625, floorSegmentMB=0.564453125, forceMergeDeletesPctAllowed=6.49092092326198, segmentsPerTier=36.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 99448 T285 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@7caa69df lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5831456a),segFN=segments_1,generation=1}
   [junit4]   2> 99448 T285 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 99452 T285 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 99453 T285 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 99453 T285 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 99453 T285 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 99453 T285 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 99454 T285 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 99454 T285 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 99454 T285 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 99454 T285 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 99455 T285 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 99455 T285 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 99455 T285 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 99456 T285 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 99456 T285 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 99456 T285 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 99457 T285 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 99459 T285 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 99461 T285 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 99461 T285 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 99462 T285 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=28, maxMergeAtOnceExplicit=17, maxMergedSegmentMB=86.638671875, floorSegmentMB=0.59375, forceMergeDeletesPctAllowed=7.494133103986719, segmentsPerTier=28.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.13880062437600876
   [junit4]   2> 99463 T285 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@7caa69df lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@5831456a),segFN=segments_1,generation=1}
   [junit4]   2> 99463 T285 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 99463 T285 oass.SolrIndexSearcher.<init> Opening Searcher@77cf6f96[collection1] main
   [junit4]   2> 99463 T285 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 99465 T285 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 99465 T285 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 99465 T285 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 99466 T285 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 99466 T285 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 99467 T285 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 99467 T285 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 99467 T285 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 99467 T285 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 99471 T286 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@77cf6f96[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 99473 T285 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 99474 T289 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:51620 collection:collection1 shard:shard1
   [junit4]   2> 99474 T220 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux@2/solr/build/solr-core/test/J0
   [junit4]   2> 99475 T220 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 99477 T220 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 99479 T289 oasc.ZkController.register We are https://127.0.0.1:51620/collection1/ and leader is https://127.0.0.1:56751/collection1/
   [junit4]   2> 99479 T289 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:51620
   [junit4]   2> 99479 T289 oasc.ZkController.checkRecovery Core needs to recover:collection1
   [junit4]   2> 99479 T289 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
   [junit4]   2> ASYNC  NEW_CORE C530 name=collection1 org.apache.solr.core.SolrCore@58cb9290 url=https://127.0.0.1:51620/collection1 node=127.0.0.1:51620_ C530_STATE=coll:collection1 core:collection1 props:{state=down, base_url=https://127.0.0.1:51620, core=collection1, node_name=127.0.0.1:51620_}
   [junit4]   2> 99480 T292 C530 P51620 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
   [junit4]   2> 99480 T292 C530 P51620 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
   [junit4]   2> 99481 T289 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 99481 T292 C530 P51620 oasc.ZkController.publish publishing core=collection1 state=recovering collection=collection1
   [junit4]   2> 99481 T292 C530 P51620 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 99483 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 99483 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 99483 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 99488 T245 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 99491 T245 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"recovering",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:51620",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:51620_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 99498 T244 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 99601 T266 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> 99601 T244 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> 99601 T253 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> 99601 T284 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> 99619 T261 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true
   [junit4]   2> 99621 T261 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 99622 T261 oasha.CoreAdminHandler.handleWaitForStateAction Will wait a max of 183 seconds to see collection1 (shard1 of collection1) have state: recovering
   [junit4]   2> 99622 T261 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true for: 0 seconds.
   [junit4]   2> 99622 T261 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={onlyIfLeaderActive=true&version=2&onlyIfLeader=true&state=recovering&core=collection1&checkLive=true&wt=javabin&nodeName=127.0.0.1:51620_&action=PREPRECOVERY&coreNodeName=core_node2} status=0 QTime=3 
   [junit4]   2> ASYNC  NEW_CORE C531 name=collection1 org.apache.solr.core.SolrCore@5a30f467 url=https://127.0.0.1:51382/collection1 node=127.0.0.1:51382_ C531_STATE=coll:control_collection core:collection1 props:{state=active, base_url=https://127.0.0.1:51382, core=collection1, node_name=127.0.0.1:51382_, leader=true}
   [junit4]   2> 99634 T239 C531 P51382 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={CONTROL=TRUE&version=2&wt=javabin} {add=[1-0 (1466643063176691712)]} 0 15
   [junit4]   2> 99636 T237 C531 P51382 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={CONTROL=TRUE&version=2&wt=javabin} {add=[2-0 (1466643063176691713)]} 0 17
   [junit4]   2> 99679 T220 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 51620
   [junit4]   2> 99680 T220 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1944586304
   [junit4]   2> 99680 T220 oasc.RecoveryStrategy.close WARN Stopping recovery for zkNodeName=core_node2core=collection1
   [junit4]   2>  C530_STATE=coll:collection1 core:collection1 props:{state=recovering, base_url=https://127.0.0.1:51620, core=collection1, node_name=127.0.0.1:51620_}
   [junit4]   2> 99797 T278 C530 P51620 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=https://127.0.0.1:56751/collection1/&version=2&update.distrib=FROMLEADER&wt=javabin} {add=[2-0 (1466643063267917825)]} 0 3
   [junit4]   2> ASYNC  NEW_CORE C532 name=collection1 org.apache.solr.core.SolrCore@2c11a31a url=https://127.0.0.1:56751/collection1 node=127.0.0.1:56751_ C532_STATE=coll:collection1 core:collection1 props:{state=active, base_url=https://127.0.0.1:56751, core=collection1, node_name=127.0.0.1:56751_, leader=true}
   [junit4]   2> 99798 T261 C532 P56751 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={version=2&wt=javabin} {add=[2-0 (1466643063267917825)]} 0 83
   [junit4]   2> 99800 T280 C530 P51620 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=https://127.0.0.1:56751/collection1/&version=2&update.distrib=FROMLEADER&wt=javabin} {add=[1-0 (1466643063267917824)]} 0 2
   [junit4]   2> 99802 T262 C532 P56751 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={version=2&wt=javabin} {add=[1-0 (1466643063267917824)]} 0 87
   [junit4]   2> ASYNC  NEW_CORE C533 name=collection1 org.apache.solr.core.SolrCore@5a30f467 url=https://127.0.0.1:51382/collection1 node=127.0.0.1:51382_ C533_STATE=coll:control_collection core:collection1 props:{state=active, base_url=https://127.0.0.1:51382, core=collection1, node_name=127.0.0.1:51382_, leader=true}
   [junit4]   2> 99818 T238 C533 P51382 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={CONTROL=TRUE&version=2&wt=javabin} {add=[2-1 (1466643063373824000)]} 0 12
   [junit4]   2> 99820 T240 C533 P51382 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={CONTROL=TRUE&version=2&wt=javabin} {add=[1-1 (1466643063375921152)]} 0 2
   [junit4]   2> ASYNC  NEW_CORE C534 name=collection1 org.apache.solr.core.SolrCore@58cb9290 url=https://127.0.0.1:51620/collection1 node=127.0.0.1:51620_ C534_STATE=coll:collection1 core:collection1 props:{state=recovering, base_url=https://127.0.0.1:51620, core=collection1, node_name=127.0.0.1:51620_}
   [junit4]   2> 99829 T277 C534 P51620 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=https://127.0.0.1:56751/collection1/&version=2&update.distrib=FROMLEADER&wt=javabin} {add=[2-1 (1466643063381164032)]} 0 1
   [junit4]   2> ASYNC  NEW_CORE C535 name=collection1 org.apache.solr.core.SolrCore@2c11a31a url=https://127.0.0.1:56751/collection1 node=127.0.0.1:56751_ C535_STATE=coll:collection1 core:collection1 props:{state=active, base_url=https://127.0.0.1:56751, core=collection1, node_name=127.0.0.1:56751_, leader=true}
   [junit4]   2> 99831 T260 C535 P56751 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={version=2&wt=javabin} {add=[2-1 (1466643063381164032)]} 0 8
   [junit4]   2> 99833 T279 C534 P51620 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=https://127.0.0.1:56751/collection1/&version=2&update.distrib=FROMLEADER&wt=javabin} {add=[1-1 (1466643063383261184)]} 0 2
   [junit4]   2> 99834 T259 C535 P56751 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={version=2&wt=javabin} {add=[1-1 (1466643063383261184)]} 0 9
   [junit4]   2> 99851 T239 C533 P51382 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={CONTROL=TRUE&version=2&wt=javabin} {add=[2-2 (1466643063409475584)]} 0 2
   [junit4]   2> 99853 T237 C533 P51382 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={CONTROL=TRUE&version=2&wt=javabin} {add=[1-2 (1466643063411572736)]} 0 1
   [junit4]   2> 99862 T278 C534 P51620 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=https://127.0.0.1:56751/collection1/&version=2&update.distrib=FROMLEADER&wt=javabin} {add=[2-2 (1466643063414718464)]} 0 1
   [junit4]   2> 99864 T261 C535 P56751 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={version=2&wt=javabin} {add=[2-2 (1466643063414718464)]} 0 9
   [junit4]   2> 99865 T280 C534 P51620 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=https://127.0.0.1:56751/collection1/&version=2&update.distrib=FROMLEADER&wt=javabin} {add=[1-2 (1466643063418912768)]} 0 2
   [junit4]   2> 99867 T262 C535 P56751 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={version=2&wt=javabin} {add=[1-2 (1466643063418912768)]} 0 9
   [junit4]   2> 99924 T238 C533 P51382 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={CONTROL=TRUE&version=2&wt=javabin} {delete=[2-2 (-1466643063487070208)]} 0 1
   [junit4]   2> 99926 T239 C533 P51382 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={CONTROL=TRUE&version=2&wt=javabin} {delete=[1-2 (-1466643063489167360)]} 0 1
   [junit4]   2> 99935 T277 C534 P51620 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=https://127.0.0.1:56751/collection1/&version=2&update.distrib=FROMLEADER&wt=javabin} {delete=[2-2 (-1466643063493361664)]} 0 1
   [junit4]   2> 99935 T279 C534 P51620 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=https://127.0.0.1:56751/collection1/&version=2&update.distrib=FROMLEADER&wt=javabin} {delete=[1-2 (-1466643063494410240)]} 0 0
   [junit4]   2> 99937 T260 C535 P56751 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={version=2&wt=javabin} {delete=[2-2 (-1466643063493361664)]} 0 7
   [junit4]   2> 99937 T259 C535 P56751 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={version=2&wt=javabin} {delete=[1-2 (-1466643063494410240)]} 0 7
   [junit4]   2> 99943 T240 C533 P51382 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={CONTROL=TRUE&version=2&wt=javabin} {add=[1-3 (1466643063505944576)]} 0 1
   [junit4]   2> 99944 T237 C533 P51382 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={CONTROL=TRUE&version=2&wt=javabin} {add=[2-3 (1466643063505944577)]} 0 2
   [junit4]   2> 99954 T278 C534 P51620 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=https://127.0.0.1:56751/collection1/&version=2&update.distrib=FROMLEADER&wt=javabin} {add=[1-3 (1466643063512236032)]} 0 1
   [junit4]   2> 99955 T280 C534 P51620 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=https://127.0.0.1:56751/collection1/&version=2&update.distrib=FROMLEADER&wt=javabin} {add=[2-3 (1466643063513284608)]} 0 1
   [junit4]   2> 99956 T262 C535 P56751 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={version=2&wt=javabin} {add=[2-3 (1466643063513284608)]} 0 8
   [junit4]   2> 99956 T261 C535 P56751 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={version=2&wt=javabin} {add=[1-3 (1466643063512236032)]} 0 8
   [junit4]   2> 100007 T238 C533 P51382 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={CONTROL=TRUE&version=2&wt=javabin} {add=[2-4 (1466643063573053440)]} 0 2
   [junit4]   2> 100007 T239 C533 P51382 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={CONTROL=TRUE&version=2&wt=javabin} {add=[1-4 (1466643063573053441)]} 0 2
   [junit4]   2> 100015 T277 C534 P51620 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=https://127.0.0.1:56751/collection1/&version=2&update.distrib=FROMLEADER&wt=javabin} {add=[2-4 (1466643063578296320)]} 0 1
   [junit4]   2> 100016 T279 C534 P51620 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=https://127.0.0.1:56751/collection1/&version=2&update.distrib=FROMLEADER&wt=javabin} {add=[1-4 (1466643063579344896)]} 0 1
   [junit4]   2> 100017 T260 C535 P56751 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={version=2&wt=javabin} {add=[2-4 (1466643063578296320)]} 0 6
   [junit4]   2> 100018 T259 C535 P56751 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={version=2&wt=javabin} {add=[1-4 (1466643063579344896)]} 0 7
   [junit4]   2> 100025 T237 C533 P51382 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={CONTROL=TRUE&version=2&wt=javabin} {add=[1-5 (1466643063592976385)]} 0 1
   [junit4]   2> 100026 T240 C533 P51382 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={CONTROL=TRUE&version=2&wt=javabin} {add=[2-5 (1466643063592976384)]} 0 2
   [junit4]   2> 100034 T278 C534 P51620 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=https://127.0.0.1:56751/collection1/&version=2&update.distrib=FROMLEADER&wt=javabin} {add=[1-5 (1466643063598219264)]} 0 1
   [junit4]   2> 100035 T280 C534 P51620 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=https://127.0.0.1:56751/collection1/&version=2&update.distrib=FROMLEADER&wt=javabin} {add=[2-5 (1466643063598219265)]} 0 1
   [junit4]   2> 100036 T262 C535 P56751 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={version=2&wt=javabin} {add=[1-5 (1466643063598219264)]} 0 7
   [junit4]   2> 100037 T261 C535 P56751 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={version=2&wt=javabin} {add=[2-5 (1466643063598219265)]} 0 7
   [junit4]   2> 100091 T239 C533 P51382 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={CONTROL=TRUE&version=2&wt=javabin} {add=[2-6 (1466643063661133824)]} 0 1
   [junit4]   2> 100093 T238 C533 P51382 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={CONTROL=TRUE&version=2&wt=javabin} {add=[1-6 (1466643063660085248)]} 0 4
   [junit4]   2> 100105 T279 C534 P51620 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=https://127.0.0.1:56751/collection1/&version=2&update.distrib=FROMLEADER&wt=javabin} {add=[2-6 (1466643063667425280)]} 0 2
   [junit4]   2> 100105 T277 C534 P51620 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=https://127.0.0.1:56751/collection1/&version=2&update.distrib=FROMLEADER&wt=javabin} {add=[1-6 (1466643063668473856)]} 0 4
   [junit4]   2> 100106 T260 C535 P56751 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={version=2&wt=javabin} {add=[2-6 (1466643063667425280)]} 0 10
   [junit4]   2> 100107 T259 C535 P56751 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={version=2&wt=javabin} {add=[1-6 (1466643063668473856)]} 0 11
   [junit4]   2> 100138 T237 C533 P51382 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={CONTROL=TRUE&version=2&wt=javabin} {add=[2-7 (1466643063710416896)]} 0 2
   [junit4]   2> 100138 T240 C533 P51382 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={CONTROL=TRUE&version=2&wt=javabin} {add=[1-7 (1466643063710416897)]} 0 1
   [junit4]   2> 100147 T278 C534 P51620 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=https://127.0.0.1:56751/collection1/&version=2&update.distrib=FROMLEADER&wt=javabin} {add=[2-7 (1466643063715659776)]} 0 1
   [junit4]   2> 100148 T279 C534 P51620 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=https://127.0.0.1:56751/collection1/&version=2&update.distrib=FROMLEADER&wt=javabin} {add=[1-7 (1466643063716708352)]} 0 1
   [junit4]   2> 100148 T262 C535 P56751 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={version=2&wt=javabin} {add=[2-7 (1466643063715659776)]} 0 6
   [junit4]   2> 100149 T260 C535 P56751 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={version=2&wt=javabin} {add=[1-7 (1466643063716708352)]} 0 7
   [junit4]   2> 100239 T239 C533 P51382 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={CONTROL=TRUE&version=2&wt=javabin} {add=[2-8 (1466643063816323072)]} 0 1
   [junit4]   2> 100240 T237 C533 P51382 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={CONTROL=TRUE&version=2&wt=javabin} {add=[1-8 (1466643063817371648)]} 0 2
   [junit4]   2> 100249 T280 C534 P51620 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=https://127.0.0.1:56751/collection1/&version=2&update.distrib=FROMLEADER&wt=javabin} {add=[1-8 (1466643063822614529)]} 0 1
   [junit4]   2> 100250 T277 C534 P51620 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=https://127.0.0.1:56751/collection1/&version=2&update.distrib=FROMLEADER&wt=javabin} {add=[2-8 (1466643063822614528)]} 0 1
   [junit4]   2> 100251 T261 C535 P56751 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={version=2&wt=javabin} {add=[1-8 (1466643063822614529)]} 0 7
   [junit4]   2> 100252 T259 C535 P56751 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={version=2&wt=javabin} {add=[2-8 (1466643063822614528)]} 0 8
   [junit4]   2> 100349 T240 C533 P51382 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={CONTROL=TRUE&version=2&wt=javabin} {add=[2-9 (1466643063931666432)]} 0 2
   [junit4]   2> 100349 T239 C533 P51382 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={CONTROL=TRUE&version=2&wt=javabin} {add=[1-9 (1466643063931666433)]} 0 2
   [junit4]   2> 100358 T278 C534 P51620 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=https://127.0.0.1:56751/collection1/&version=2&update.distrib=FROMLEADER&wt=javabin} {ad

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

[junit4]   2> 	        at org.apache.solr.cloud.ChaosMonkey.stop(ChaosMonkey.java:560)
   [junit4]   2> 	        at org.apache.solr.cloud.AbstractFullDistribZkTestBase.destroyServers(AbstractFullDistribZkTestBase.java:1453)
   [junit4]   2> 	        at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:866)
   [junit4]   2> 	        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
   [junit4]   2> 	        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
   [junit4]   2> 	        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
   [junit4]   2> 	        at java.lang.reflect.Method.invoke(Method.java:606)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1618)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:827)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:877)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
   [junit4]   2> 	        at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
   [junit4]   2> 	        at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
   [junit4]   2> 	        at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
   [junit4]   2> 	        at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
   [junit4]   2> 	        at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
   [junit4]   2> 	        at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:793)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:453)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:836)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:738)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:772)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:783)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
   [junit4]   2> 	        at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
   [junit4]   2> 	        at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	        at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
   [junit4]   2> 	        at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
   [junit4]   2> 	        at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:65)
   [junit4]   2> 	        at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
   [junit4]   2> 	        at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:360)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 	  17) Thread[id=257, name=qtp971878228-257 Acceptor0 SslSelectChannelConnector@127.0.0.1:56751, state=BLOCKED, group=TGRP-RecoveryZkTest]
   [junit4]   2> 	        at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:956)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 	  18) Thread[id=271, name=coreZkRegister-102-thread-1, state=WAITING, group=TGRP-RecoveryZkTest]
   [junit4]   2> 	        at sun.misc.Unsafe.park(Native Method)
   [junit4]   2> 	        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:186)
   [junit4]   2> 	        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2043)
   [junit4]   2> 	        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
   [junit4]   2> 	        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 	  19) Thread[id=303, name=qtp1193738788-303 Selector1, state=RUNNABLE, group=TGRP-RecoveryZkTest]
   [junit4]   2> 	        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:86)
   [junit4]   2> 	        at sun.nio.ch.SelectorImpl.selectNow(SelectorImpl.java:106)
   [junit4]   2> 	        at org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:536)
   [junit4]   2> 	        at org.eclipse.jetty.io.nio.SelectorManager$1.run(SelectorManager.java:290)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> NOTE: test params are: codec=CheapBastard, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=nl, timezone=IST
   [junit4]   2> NOTE: Linux 3.8.0-38-generic amd64/Oracle Corporation 1.7.0_60-ea (64-bit)/cpus=8,threads=25,free=74626720,total=160665600
   [junit4]   2> NOTE: All tests run in this JVM: [TestMiniSolrCloudCluster, TestRandomDVFaceting, TestMaxScoreQueryParser, SolrIndexSplitterTest, TestReversedWildcardFilterFactory, TestManagedResourceStorage, TermVectorComponentTest, RecoveryZkTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=RecoveryZkTest -Dtests.seed=D32612A5C272D312 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=nl -Dtests.timezone=IST -Dtests.file.encoding=ISO-8859-1
   [junit4] ERROR   0.00s J0 | RecoveryZkTest (suite) <<<
   [junit4]    > Throwable #1: java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([D32612A5C272D312]:0)
   [junit4] Completed on J0 in 7223.51s, 1 test, 2 errors <<< FAILURES!

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

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



Mime
View raw message