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-trunk-Linux (64bit/jdk1.7.0_60-ea-b10) - Build # 9911 - Still Failing!
Date Wed, 26 Mar 2014 12:57:20 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Linux/9911/
Java: 64bit/jdk1.7.0_60-ea-b10 -XX:-UseCompressedOops -XX:+UseConcMarkSweepGC

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




Build Log:
[...truncated 11371 lines...]
   [junit4] Suite: org.apache.solr.cloud.RecoveryZkTest
   [junit4]   2> 739012 T4588 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (true)
   [junit4]   2> 739012 T4588 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /qdw/
   [junit4]   2> 739016 T4588 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./solrtest-RecoveryZkTest-1395831395260
   [junit4]   2> 739016 T4588 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 739017 T4589 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 739117 T4588 oasc.ZkTestServer.run start zk server on port:59894
   [junit4]   2> 739118 T4588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 739128 T4595 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c38f7ad name:ZooKeeperConnection Watcher:127.0.0.1:59894 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 739128 T4588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 739128 T4588 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 739132 T4588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 739133 T4597 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@73a41d1b name:ZooKeeperConnection Watcher:127.0.0.1:59894/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 739134 T4588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 739134 T4588 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 739136 T4588 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 739137 T4588 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 739138 T4588 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 739139 T4588 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 739140 T4588 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 739142 T4588 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
   [junit4]   2> 739142 T4588 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 739144 T4588 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 739145 T4588 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 739146 T4588 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 739146 T4588 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 739149 T4588 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 739149 T4588 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 739150 T4588 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 739151 T4588 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 739152 T4588 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 739152 T4588 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 739154 T4588 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 739155 T4588 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 739156 T4588 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 739156 T4588 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 739158 T4588 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 739158 T4588 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 739160 T4588 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 739161 T4588 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 739163 T4588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 739164 T4599 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7733ee56 name:ZooKeeperConnection Watcher:127.0.0.1:59894/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 739164 T4588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 739374 T4588 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 739377 T4588 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 739380 T4588 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:60275
   [junit4]   2> 739382 T4588 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 739382 T4588 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 739382 T4588 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1395831395409
   [junit4]   2> 739383 T4588 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1395831395409/'
   [junit4]   2> 739395 T4588 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1395831395409/solr.xml
   [junit4]   2> 739426 T4588 oasc.CoreContainer.<init> New CoreContainer 1055075769
   [junit4]   2> 739427 T4588 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1395831395409/]
   [junit4]   2> 739427 T4588 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 739428 T4588 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 739428 T4588 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 739428 T4588 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 739428 T4588 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 739429 T4588 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 739429 T4588 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 739429 T4588 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 739429 T4588 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 739431 T4588 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 739431 T4588 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 739432 T4588 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 739432 T4588 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59894/solr
   [junit4]   2> 739432 T4588 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 739433 T4588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 739434 T4610 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5af6945c name:ZooKeeperConnection Watcher:127.0.0.1:59894 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 739434 T4588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 739436 T4588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 739437 T4612 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@47eadf35 name:ZooKeeperConnection Watcher:127.0.0.1:59894/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 739437 T4588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 739438 T4588 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 739440 T4588 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 739441 T4588 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 739443 T4588 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 739445 T4588 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 739446 T4588 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 739448 T4588 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:60275_qdw
   [junit4]   2> 739450 T4588 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:60275_qdw
   [junit4]   2> 739451 T4588 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 739453 T4588 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 739460 T4588 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:60275_qdw
   [junit4]   2> 739460 T4588 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 739462 T4588 oasc.Overseer.start Overseer (id=91477206319890436-127.0.0.1:60275_qdw-n_0000000000) starting
   [junit4]   2> 739464 T4588 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 739471 T4614 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 739471 T4588 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 739471 T4614 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 739472 T4588 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 739473 T4588 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 739475 T4613 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 739478 T4615 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 739478 T4615 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 739479 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 739479 T4615 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 739480 T4613 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 739481 T4613 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:60275/qdw",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:60275_qdw",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 739481 T4613 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 739481 T4613 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 739485 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 739485 T4612 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> 740480 T4615 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 740480 T4615 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 740481 T4615 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 740481 T4615 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 740482 T4615 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 740482 T4615 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1395831395409/collection1/'
   [junit4]   2> 740482 T4615 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1395831395409/collection1/lib/.svn/' to classloader
   [junit4]   2> 740483 T4615 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1395831395409/collection1/lib/classes/' to classloader
   [junit4]   2> 740483 T4615 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1395831395409/collection1/lib/README' to classloader
   [junit4]   2> 740508 T4615 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 740539 T4615 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 740541 T4615 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 740546 T4615 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 740816 T4615 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 740817 T4615 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 740818 T4615 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 740821 T4615 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 740836 T4615 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 740836 T4615 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 740836 T4615 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1395831395409/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1395831395260/control/data/
   [junit4]   2> 740836 T4615 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@41d1465c
   [junit4]   2> 740837 T4615 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1395831395260/control/data
   [junit4]   2> 740837 T4615 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1395831395260/control/data/index/
   [junit4]   2> 740837 T4615 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1395831395260/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 740837 T4615 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1395831395260/control/data/index
   [junit4]   2> 740838 T4615 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=23, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.314084743067576]
   [junit4]   2> 740838 T4615 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@3e63d565 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@105725a4),segFN=segments_1,generation=1}
   [junit4]   2> 740838 T4615 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 740842 T4615 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 740842 T4615 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 740842 T4615 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 740842 T4615 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 740842 T4615 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 740843 T4615 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 740843 T4615 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 740843 T4615 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 740843 T4615 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 740844 T4615 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 740844 T4615 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 740844 T4615 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 740844 T4615 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 740845 T4615 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 740845 T4615 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 740845 T4615 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 740846 T4615 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 740848 T4615 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 740849 T4615 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 740850 T4615 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 740850 T4615 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=34, maxMergedSegmentMB=74.349609375, floorSegmentMB=1.142578125, forceMergeDeletesPctAllowed=5.120953378894949, segmentsPerTier=37.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.18522701469733677
   [junit4]   2> 740850 T4615 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@3e63d565 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@105725a4),segFN=segments_1,generation=1}
   [junit4]   2> 740851 T4615 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 740851 T4615 oass.SolrIndexSearcher.<init> Opening Searcher@4ada27b0[collection1] main
   [junit4]   2> 740851 T4615 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 740852 T4615 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 740852 T4615 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 740852 T4615 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 740852 T4615 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 740852 T4615 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 740853 T4615 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 740853 T4615 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 740853 T4615 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 740853 T4615 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 740855 T4616 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4ada27b0[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 740856 T4615 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 740865 T4619 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:60275/qdw collection:control_collection shard:shard1
   [junit4]   2> 740865 T4588 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 740866 T4588 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 740866 T4619 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 740869 T4588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 740870 T4619 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 740870 T4621 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5c85b274 name:ZooKeeperConnection Watcher:127.0.0.1:59894/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 740871 T4588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 740871 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 740871 T4588 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 740872 T4619 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 740872 T4619 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C2104 name=collection1 org.apache.solr.core.SolrCore@12a7a3f1 url=https://127.0.0.1:60275/qdw/collection1 node=127.0.0.1:60275_qdw C2104_STATE=coll:control_collection core:collection1 props:{state=down, base_url=https://127.0.0.1:60275/qdw, core=collection1, node_name=127.0.0.1:60275_qdw}
   [junit4]   2> 740872 T4619 C2104 P60275 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:60275/qdw/collection1/
   [junit4]   2> 740872 T4613 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 740872 T4619 C2104 P60275 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 740873 T4619 C2104 P60275 oasc.SyncStrategy.syncToMe https://127.0.0.1:60275/qdw/collection1/ has no replicas
   [junit4]   2> 740873 T4619 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:60275/qdw/collection1/ shard1
   [junit4]   2> 740873 T4619 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 740873 T4588 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 740874 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 740878 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 740881 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 740982 T4621 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> 740982 T4612 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> 741029 T4619 oasc.ZkController.register We are https://127.0.0.1:60275/qdw/collection1/ and leader is https://127.0.0.1:60275/qdw/collection1/
   [junit4]   2> 741029 T4619 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:60275/qdw
   [junit4]   2> 741029 T4619 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 741029 T4619 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 741029 T4619 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 741030 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 741030 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 741030 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 741030 T4619 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 741031 T4613 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 741032 T4613 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:60275/qdw",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:60275_qdw",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 741033 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 741092 T4588 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 741092 T4588 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 741095 T4588 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 741096 T4588 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:40052
   [junit4]   2> 741098 T4588 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 741098 T4588 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 741098 T4588 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1395831397118
   [junit4]   2> 741099 T4588 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1395831397118/'
   [junit4]   2> 741111 T4588 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1395831397118/solr.xml
   [junit4]   2> 741137 T4621 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> 741137 T4612 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> 741146 T4588 oasc.CoreContainer.<init> New CoreContainer 58481025
   [junit4]   2> 741146 T4588 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1395831397118/]
   [junit4]   2> 741147 T4588 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 741147 T4588 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 741148 T4588 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 741148 T4588 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 741148 T4588 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 741148 T4588 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 741148 T4588 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 741149 T4588 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 741149 T4588 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 741151 T4588 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 741151 T4588 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 741151 T4588 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 741152 T4588 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59894/solr
   [junit4]   2> 741152 T4588 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 741152 T4588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 741155 T4632 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10ad14a8 name:ZooKeeperConnection Watcher:127.0.0.1:59894 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 741155 T4588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 741156 T4588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 741157 T4634 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@170e8785 name:ZooKeeperConnection Watcher:127.0.0.1:59894/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 741158 T4588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 741161 T4588 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 742163 T4588 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40052_qdw
   [junit4]   2> 742164 T4588 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40052_qdw
   [junit4]   2> 742166 T4621 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 742166 T4634 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 742166 T4612 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 742171 T4635 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 742171 T4635 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 742172 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 742172 T4635 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 742172 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 742172 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 742173 T4613 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 742173 T4613 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:40052/qdw",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:40052_qdw",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 742173 T4613 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1]
   [junit4]   2> 742173 T4613 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 742179 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 742281 T4621 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> 742281 T4634 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> 742281 T4612 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> 743172 T4635 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 743172 T4635 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 743173 T4635 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 743173 T4635 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 743174 T4635 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 743174 T4635 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1395831397118/collection1/'
   [junit4]   2> 743174 T4635 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1395831397118/collection1/lib/.svn/' to classloader
   [junit4]   2> 743175 T4635 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1395831397118/collection1/lib/classes/' to classloader
   [junit4]   2> 743175 T4635 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1395831397118/collection1/lib/README' to classloader
   [junit4]   2> 743212 T4635 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 743242 T4635 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 743243 T4635 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 743249 T4635 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 743497 T4635 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 743499 T4635 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 743500 T4635 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 743503 T4635 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 743527 T4635 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 743528 T4635 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 743528 T4635 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1395831397118/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1395831395260/jetty1/
   [junit4]   2> 743528 T4635 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@41d1465c
   [junit4]   2> 743529 T4635 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1395831395260/jetty1
   [junit4]   2> 743529 T4635 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1395831395260/jetty1/index/
   [junit4]   2> 743529 T4635 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1395831395260/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 743529 T4635 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1395831395260/jetty1/index
   [junit4]   2> 743530 T4635 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=23, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.314084743067576]
   [junit4]   2> 743530 T4635 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@683d8bb6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@23e772d0),segFN=segments_1,generation=1}
   [junit4]   2> 743530 T4635 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 743535 T4635 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 743535 T4635 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 743535 T4635 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 743535 T4635 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 743536 T4635 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 743536 T4635 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 743536 T4635 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 743537 T4635 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 743537 T4635 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 743537 T4635 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 743538 T4635 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 743538 T4635 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 743538 T4635 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 743538 T4635 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 743539 T4635 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 743539 T4635 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 743540 T4635 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 743542 T4635 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 743544 T4635 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 743544 T4635 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 743544 T4635 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=34, maxMergedSegmentMB=74.349609375, floorSegmentMB=1.142578125, forceMergeDeletesPctAllowed=5.120953378894949, segmentsPerTier=37.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.18522701469733677
   [junit4]   2> 743545 T4635 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@683d8bb6 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@23e772d0),segFN=segments_1,generation=1}
   [junit4]   2> 743545 T4635 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 743545 T4635 oass.SolrIndexSearcher.<init> Opening Searcher@114c0ac[collection1] main
   [junit4]   2> 743545 T4635 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 743546 T4635 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 743546 T4635 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 743547 T4635 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 743547 T4635 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 743547 T4635 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 743547 T4635 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 743548 T4635 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 743548 T4635 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 743548 T4635 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 743550 T4636 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@114c0ac[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 743552 T4635 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 743553 T4639 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:40052/qdw collection:collection1 shard:shard1
   [junit4]   2> 743553 T4588 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 743553 T4588 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 743556 T4639 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 743561 T4639 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 743562 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 743562 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 743563 T4639 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 743563 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 743563 T4639 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C2105 name=collection1 org.apache.solr.core.SolrCore@2863cd79 url=https://127.0.0.1:40052/qdw/collection1 node=127.0.0.1:40052_qdw C2105_STATE=coll:collection1 core:collection1 props:{state=down, base_url=https://127.0.0.1:40052/qdw, core=collection1, node_name=127.0.0.1:40052_qdw}
   [junit4]   2> 743563 T4639 C2105 P40052 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:40052/qdw/collection1/
   [junit4]   2> 743563 T4639 C2105 P40052 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 743563 T4613 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 743563 T4639 C2105 P40052 oasc.SyncStrategy.syncToMe https://127.0.0.1:40052/qdw/collection1/ has no replicas
   [junit4]   2> 743564 T4639 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:40052/qdw/collection1/ shard1
   [junit4]   2> 743564 T4639 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 743565 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 743567 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 743569 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 743671 T4612 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> 743671 T4634 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> 743671 T4621 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> 743717 T4639 oasc.ZkController.register We are https://127.0.0.1:40052/qdw/collection1/ and leader is https://127.0.0.1:40052/qdw/collection1/
   [junit4]   2> 743718 T4639 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:40052/qdw
   [junit4]   2> 743718 T4639 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 743718 T4639 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 743718 T4639 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 743719 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 743719 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 743719 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 743719 T4639 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 743720 T4613 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 743721 T4613 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:40052/qdw",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:40052_qdw",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 743723 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 743768 T4588 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 743769 T4588 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 743771 T4588 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 743772 T4588 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:58364
   [junit4]   2> 743774 T4588 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 743775 T4588 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 743775 T4588 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./org.apache.solr.cloud.RecoveryZkTest-jetty2-1395831399799
   [junit4]   2> 743775 T4588 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.RecoveryZkTest-jetty2-1395831399799/'
   [junit4]   2> 743787 T4588 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1395831399799/solr.xml
   [junit4]   2> 743820 T4588 oasc.CoreContainer.<init> New CoreContainer 864195439
   [junit4]   2> 743820 T4588 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./org.apache.solr.cloud.RecoveryZkTest-jetty2-1395831399799/]
   [junit4]   2> 743821 T4588 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 743821 T4588 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 743821 T4588 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 743821 T4588 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 743821 T4588 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 743822 T4588 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 743822 T4588 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 743822 T4588 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 743822 T4588 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 743824 T4634 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> 743824 T4621 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> 743824 T4612 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> 743824 T4588 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 743825 T4588 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 743825 T4588 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 743826 T4588 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:59894/solr
   [junit4]   2> 743826 T4588 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 743827 T4588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 743828 T4650 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13710722 name:ZooKeeperConnection Watcher:127.0.0.1:59894 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 743828 T4588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 743829 T4588 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 743830 T4652 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@155efc72 name:ZooKeeperConnection Watcher:127.0.0.1:59894/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 743830 T4588 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 743835 T4588 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 744836 T4588 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58364_qdw
   [junit4]   2> 744838 T4588 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58364_qdw
   [junit4]   2> 744839 T4634 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 744839 T4652 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 744839 T4612 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 744839 T4621 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 744845 T4653 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 744845 T4653 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 744846 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 744846 T4653 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 744846 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 744847 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 744848 T4613 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 744849 T4613 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:58364/qdw",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:58364_qdw",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 744849 T4613 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
   [junit4]   2> 744849 T4613 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 744856 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 744957 T4621 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> 744957 T4634 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> 744957 T4652 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> 744957 T4612 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> 745847 T4653 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 745847 T4653 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 745848 T4653 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 745848 T4653 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 745849 T4653 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 745849 T4653 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './org.apache.solr.cloud.RecoveryZkTest-jetty2-1395831399799/collection1/'
   [junit4]   2> 745849 T4653 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1395831399799/collection1/lib/.svn/' to classloader
   [junit4]   2> 745849 T4653 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1395831399799/collection1/lib/classes/' to classloader
   [junit4]   2> 745850 T4653 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1395831399799/collection1/lib/README' to classloader
   [junit4]   2> 745900 T4653 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
   [junit4]   2> 745939 T4653 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 745940 T4653 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 745946 T4653 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 746210 T4653 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 746212 T4653 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 746213 T4653 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 746216 T4653 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 746233 T4653 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 746233 T4653 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 746233 T4653 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./org.apache.solr.cloud.RecoveryZkTest-jetty2-1395831399799/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1395831395260/jetty2/
   [junit4]   2> 746233 T4653 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@41d1465c
   [junit4]   2> 746234 T4653 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1395831395260/jetty2
   [junit4]   2> 746234 T4653 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1395831395260/jetty2/index/
   [junit4]   2> 746235 T4653 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1395831395260/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 746235 T4653 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1395831395260/jetty2/index
   [junit4]   2> 746235 T4653 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=23, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.314084743067576]
   [junit4]   2> 746236 T4653 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@34dd709f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@60fa3b38),segFN=segments_1,generation=1}
   [junit4]   2> 746237 T4653 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 746243 T4653 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 746243 T4653 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 746244 T4653 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 746244 T4653 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 746244 T4653 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 746244 T4653 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 746245 T4653 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 746245 T4653 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 746245 T4653 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 746246 T4653 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 746247 T4653 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 746247 T4653 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 746247 T4653 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 746248 T4653 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 746248 T4653 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 746249 T4653 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 746249 T4653 oasc.RequestHandlers.initHandlersFromConfig created /admin/fileedit: solr.admin.EditFileRequestHandler
   [junit4]   2> 746252 T4653 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 746254 T4653 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 746254 T4653 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 746255 T4653 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=34, maxMergedSegmentMB=74.349609375, floorSegmentMB=1.142578125, forceMergeDeletesPctAllowed=5.120953378894949, segmentsPerTier=37.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.18522701469733677
   [junit4]   2> 746255 T4653 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@34dd709f lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@60fa3b38),segFN=segments_1,generation=1}
   [junit4]   2> 746255 T4653 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 746256 T4653 oass.SolrIndexSearcher.<init> Opening Searcher@72059540[collection1] main
   [junit4]   2> 746256 T4653 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 746257 T4653 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 746257 T4653 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 746257 T4653 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 746257 T4653 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 746257 T4653 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 746258 T4653 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 746258 T4653 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 746258 T4653 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 746258 T4653 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 746261 T4654 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@72059540[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 746263 T4653 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 746264 T4657 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:58364/qdw collection:collection1 shard:shard1
   [junit4]   2> 746264 T4588 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-trunk-Linux/solr/build/solr-core/test/J0
   [junit4]   2> 746264 T4588 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 746266 T4588 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 746267 T4657 oasc.ZkController.register We are https://127.0.0.1:58364/qdw/collection1/ and leader is https://127.0.0.1:40052/qdw/collection1/
   [junit4]   2> 746267 T4657 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:58364/qdw
   [junit4]   2> 746268 T4657 oasc.ZkController.checkRecovery Core needs to recover:collection1
   [junit4]   2> 746268 T4657 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
   [junit4]   2> ASYNC  NEW_CORE C2106 name=collection1 org.apache.solr.core.SolrCore@5d5ec64 url=https://127.0.0.1:58364/qdw/collection1 node=127.0.0.1:58364_qdw C2106_STATE=coll:collection1 core:collection1 props:{state=down, base_url=https://127.0.0.1:58364/qdw, core=collection1, node_name=127.0.0.1:58364_qdw}
   [junit4]   2> 746268 T4659 C2106 P58364 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
   [junit4]   2> 746268 T4657 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 746270 T4659 C2106 P58364 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
   [junit4]   2> 746270 T4659 C2106 P58364 oasc.ZkController.publish publishing core=collection1 state=recovering collection=collection1
   [junit4]   2> 746271 T4659 C2106 P58364 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 746272 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 746272 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 746272 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 746273 T4613 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 746273 T4613 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:58364/qdw",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:58364_qdw",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 746277 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 746330 T4628 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: core_node2, state: recovering, checkLive: true, onlyIfLeader: true
   [junit4]   2> 746331 T4628 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 746332 T4628 oasha.CoreAdminHandler.handleWaitForStateAction Will wait a max of 183 seconds to see collection1 (shard1 of collection1) have state: recovering
   [junit4]   2> ASYNC  NEW_CORE C2107 name=collection1 org.apache.solr.core.SolrCore@12a7a3f1 url=https://127.0.0.1:60275/qdw/collection1 node=127.0.0.1:60275_qdw C2107_STATE=coll:control_collection core:collection1 props:{state=active, base_url=https://127.0.0.1:60275/qdw, core=collection1, node_name=127.0.0.1:60275_qdw, leader=true}
   [junit4]   2> 746340 T4608 C2107 P60275 oasup.LogUpdateProcessor.finish [collection1] webapp=/qdw path=/update params={version=2&wt=javabin&CONTROL=TRUE} {add=[2-0 (1463635308793823232)]} 0 2
   [junit4]   2> 746344 T4607 C2107 P60275 oasup.LogUpdateProcessor.finish [collection1] webapp=/qdw path=/update params={version=2&wt=javabin&CONTROL=TRUE} {add=[1-0 (1463635308799066112)]} 0 1
   [junit4]   2> 746381 T4621 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> 746381 T4652 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> 746381 T4634 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> 746381 T4612 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>  C2106_STATE=coll:collection1 core:collection1 props:{state=recovering, base_url=https://127.0.0.1:58364/qdw, core=collection1, node_name=127.0.0.1:58364_qdw}
   [junit4]   2> 746460 T4647 C2106 P58364 oasup.LogUpdateProcessor.finish [collection1] webapp=/qdw path=/update params={distrib.from=https://127.0.0.1:40052/qdw/collection1/&version=2&update.distrib=FROMLEADER&wt=javabin} {add=[2-0 (1463635308856737792)]} 0 2
   [junit4]   2> ASYNC  NEW_CORE C2108 name=collection1 org.apache.solr.core.SolrCore@2863cd79 url=https://127.0.0.1:40052/qdw/collection1 node=127.0.0.1:40052_qdw C2108_STATE=coll:collection1 core:collection1 props:{state=active, base_url=https://127.0.0.1:40052/qdw, core=collection1, node_name=127.0.0.1:40052_qdw, leader=true}
   [junit4]   2> 746460 T4630 C2108 P40052 oasup.LogUpdateProcessor.finish [collection1] webapp=/qdw path=/update params={version=2&wt=javabin} {add=[2-0 (1463635308856737792)]} 0 62
   [junit4]   2> 746467 T4645 C2106 P58364 oasup.LogUpdateProcessor.finish [collection1] webapp=/qdw path=/update params={distrib.from=https://127.0.0.1:40052/qdw/collection1/&version=2&update.distrib=FROMLEADER&wt=javabin} {add=[1-0 (1463635308866174976)]} 0 1
   [junit4]   2> 746468 T4627 C2108 P40052 oasup.LogUpdateProcessor.finish [collection1] webapp=/qdw path=/update params={version=2&wt=javabin} {add=[1-0 (1463635308866174976)]} 0 61
   [junit4]   2> 746468 T4588 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 58364
   [junit4]   2> 746469 T4588 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=864195439
   [junit4]   2> 746470 T4588 oasc.RecoveryStrategy.close WARN Stopping recovery for zkNodeName=core_node2core=collection1
   [junit4]   2> 746471 T4659 C2106 P58364 oasc.SolrException.log ERROR Error while trying to recover. core=collection1:java.util.concurrent.ExecutionException: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: https://127.0.0.1:40052/qdw
   [junit4]   2> 		at java.util.concurrent.FutureTask.report(FutureTask.java:122)
   [junit4]   2> 		at java.util.concurrent.FutureTask.get(FutureTask.java:188)
   [junit4]   2> 		at org.apache.solr.cloud.RecoveryStrategy.sendPrepRecoveryCmd(RecoveryStrategy.java:611)
   [junit4]   2> 		at org.apache.solr.cloud.RecoveryStrategy.doRecovery(RecoveryStrategy.java:370)
   [junit4]   2> 		at org.apache.solr.cloud.RecoveryStrategy.run(RecoveryStrategy.java:235)
   [junit4]   2> 	Caused by: org.apache.solr.client.solrj.SolrServerException: IOException occured when talking to server at: https://127.0.0.1:40052/qdw
   [junit4]   2> 		at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:565)
   [junit4]   2> 		at org.apache.solr.client.solrj.impl.HttpSolrServer$1.call(HttpSolrServer.java:244)
   [junit4]   2> 		at org.apache.solr.client.solrj.impl.HttpSolrServer$1.call(HttpSolrServer.java:240)
   [junit4]   2> 		at java.util.concurrent.FutureTask.run(FutureTask.java:262)
   [junit4]   2> 		at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
   [junit4]   2> 		at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]   2> 		at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 	Caused by: java.net.SocketException: Socket closed
   [junit4]   2> 		at java.net.SocketInputStream.socketRead0(Native Method)
   [junit4]   2> 		at java.net.SocketInputStream.read(SocketInputStream.java:152)
   [junit4]   2> 		at java.net.SocketInputStream.read(SocketInputStream.java:122)
   [junit4]   2> 		at sun.security.ssl.InputRecord.readFully(InputRecord.java:442)
   [junit4]   2> 		at sun.security.ssl.InputRecord.read(InputRecord.java:480)
   [junit4]   2> 		at sun.security.ssl.SSLSocketImpl.readRecord(SSLSocketImpl.java:927)
   [junit4]   2> 		at sun.security.ssl.SSLSocketImpl.readDataRecord(SSLSocketImpl.java:884)
   [junit4]   2> 		at sun.security.ssl.AppInputStream.read(AppInputStream.java:102)
   [junit4]   2> 		at org.apache.http.impl.io.AbstractSessionInputBuffer.fillBuffer(AbstractSessionInputBuffer.java:160)
   [junit4]   2> 		at org.apache.http.impl.io.SocketInputBuffer.fillBuffer(SocketInputBuffer.java:84)
   [junit4]   2> 		at org.apache.http.impl.io.AbstractSessionInputBuffer.readLine(AbstractSessionInputBuffer.java:273)
   [junit4]   2> 		at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:140)
   [junit4]   2> 		at org.apache.http.impl.conn.DefaultHttpResponseParser.parseHead(DefaultHttpResponseParser.java:57)
   [junit4]   2> 		at org.apache.http.impl.io.AbstractMessageParser.parse(AbstractMessageParser.java:260)
   [junit4]   2> 		at org.apache.http.impl.AbstractHttpClientConnection.receiveResponseHeader(AbstractHttpClientConnection.java:283)
   [junit4]   2> 		at org.apache.http.impl.conn.DefaultClientConnection.receiveResponseHeader(DefaultClientConnection.java:251)
   [junit4]   2> 		at org.apache.http.impl.conn.ManagedClientConnectionImpl.receiveResponseHeader(ManagedClientConnectionImpl.java:197)
   [junit4]   2> 		at org.apache.http.protocol.HttpRequestExecutor.doReceiveResponse(HttpRequestExecutor.java:271)
   [junit4]   2> 		at org.apache.http.protocol.HttpRequestExecutor.execute(HttpRequestExecutor.java:123)
   [junit4]   2> 		at org.apache.http.impl.client.DefaultRequestDirector.tryExecute(DefaultRequestDirector.java:682)
   [junit4]   2> 		at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:486)
   [junit4]   2> 		at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:863)
   [junit4]   2> 		at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82)
   [junit4]   2> 		at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106)
   [junit4]   2> 		at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:57)
   [junit4]   2> 		at org.apache.solr.client.solrj.impl.HttpSolrServer.executeMethod(HttpSolrServer.java:451)
   [junit4]   2> 		... 6 more
   [junit4]   2> 	
   [junit4]   2> 746471 T4659 C2106 P58364 oasc.RecoveryStrategy.doRecovery ERROR Recovery failed - trying again... (0) core=collection1
   [junit4]   2> 746472 T4659 C2106 P58364 oasc.SolrException.log ERROR Recovery failed - interrupted. core=collection1
   [junit4]   2> 746472 T4659 C2106 P58364 oasc.SolrException.log ERROR Recovery failed - I give up. core=collection1
   [junit4]   2> 746472 T4659 C2106 P58364 oasc.ZkController.publish publishing core=collection1 state=recovery_failed collection=collection1
   [junit4]   2> 746472 T4659 C2106 P58364 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 746472 T4607 C2107 P60275 oasup.LogUpdateProcessor.finish [collection1] webapp=/qdw path=/update params={version=2&wt=javabin&CONTROL=TRUE} {add=[2-1 (1463635308934332416)]} 0 0
   [junit4]   2> 746473 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 746474 T4659 C2106 P58364 oasc.RecoveryStrategy.close WARN Stopping recovery for zkNodeName=core_node2core=collection1
   [junit4]   2> 746474 T4613 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 746475 T4659 C2106 P58364 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
   [junit4]   2> 746474 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 746475 T4588 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 746475 T4588 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 746475 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 746476 T4613 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"recovery_failed",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:58364/qdw",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:58364_qdw",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 746478 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 746478 T4588 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@5d5ec64
   [junit4]   2> 746481 T4605 C2107 P60275 oasup.LogUpdateProcessor.finish [collection1] webapp=/qdw path=/update params={version=2&wt=javabin&CONTROL=TRUE} {add=[1-1 (1463635308942721024)]} 0 1
   [junit4]   2> 746481 T4613 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:58364/qdw",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:58364_qdw",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 746484 T4612 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 746484 T4663 oasu.StreamingSolrServers$1.handleError ERROR error org.apache.solr.common.SolrException: Can not find: /qdw/collection1/update
   [junit4]   2> 
   [junit4]   2> 
   [junit4]   2> 
   [junit4]   2> request: https://127.0.0.1:58364/qdw/collection1/update?update.distrib=FROMLEADER&distrib.from=https%3A%2F%2F127.0.0.1%3A40052%2Fqdw%2Fcollection1%2F&wt=javabin&version=2
   [junit4]   2> 	at org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrServer$Runner.run(ConcurrentUpdateSolrServer.java:240)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> ASYNC  NEW_CORE C2109 name=collection1 org.apache.solr.core.SolrCore@2863cd79 url=https://127.0.0.1:40052/qdw/collection1 node=127.0.0.1:40052_qdw C2109_STATE=coll:collection1 core:collection1 props:{state=active, base_url=https://127.0.0.1:40052/qdw, core=collection1, node_name=127.0.0.1:40052_qdw, leader=true}
   [junit4]   2> 746495 T4630 C2109 P40052 oasup.DistributedUpdateProcessor.doFinish WARN Error sending update org.apache.solr.common.SolrException: Can not find: /qdw/collection1/update
   [junit4]   2> 
   [junit4]   2> 
   [junit4]   2> 
   [junit4]   2> request: https://127.0.0.1:58364/qdw/collection1/update?update.distrib=FROMLEADER&distrib.from=https%3A%2F%2F127.0.0.1%3A40052%2Fqdw%2Fcollection1%2F&wt=javabin&version=2
   [junit4]   2> 	at org.apache.solr.client.solrj.impl.ConcurrentUpdateSolrServer$Runner.run(ConcurrentUpdateSolrServer.java:240)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
   [junit4]   2> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 746496 T4663 oasup.DistributedUpdateProcessor$1.run try and ask https://127.0.0.1:58364/qdw to recover
   [junit4]   2> 746496 T4630 C2109 P40052 oasup.LogUpdateProcessor.finish [collection1] webapp=/qdw path=/update params={version=2&wt=javabin} {add=[2-1 (1463635308939575296)]} 0 19
   [junit4]   2> 746497 T4588 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=2,adds=2,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=2,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=0}
   [junit4]   2> 746497 T4588 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 746497 T4588 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 746497 T4588 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> ASYNC  NEW_CORE C2110 name=collection1 org.apache.solr.core.SolrCore@5d5ec64 url=https://127.0.0.1:58364/qdw/collection1 node=127.0.0.1:58364_qdw C2110_STATE=coll:collection1 core:collection1 props:{state=recovering, base_url=https://127.0.0.1:58364/qdw, core=collection1, node_name=127.0.0.1:58364_qdw}
   [junit4]   2> 746500 T4588 C2110 P58364 oasc

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

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> 	  14) Thread[id=4680, name=searcherExecutor-2062-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> 	  15) Thread[id=4668, name=qtp522691791-4668 Selector1, state=RUNNABLE, group=TGRP-RecoveryZkTest]
   [junit4]   2> 	        at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
   [junit4]   2> 	        at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
   [junit4]   2> 	        at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
   [junit4]   2> 	        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
   [junit4]   2> 	        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
   [junit4]   2> 	        at org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:569)
   [junit4]   2> 	        at org.eclipse.jetty.io.nio.SelectorManager$1.run(SelectorManager.java:290)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 	  16) Thread[id=4639, name=coreZkRegister-2042-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> 	  17) Thread[id=4633, name=TEST-RecoveryZkTest.testDistribSearch-seed#[CDB667E8A1E7CCF3]-SendThread(127.0.0.1:59894), state=TIMED_WAITING, group=TGRP-RecoveryZkTest]
   [junit4]   2> 	        at java.lang.Thread.sleep(Native Method)
   [junit4]   2> 	        at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:101)
   [junit4]   2> 	        at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:940)
   [junit4]   2> 	        at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1003)
   [junit4]   2> 	  18) Thread[id=4624, name=qtp1550174314-4624 Selector1, state=RUNNABLE, group=TGRP-RecoveryZkTest]
   [junit4]   2> 	        at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
   [junit4]   2> 	        at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
   [junit4]   2> 	        at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
   [junit4]   2> 	        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
   [junit4]   2> 	        at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
   [junit4]   2> 	        at org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:569)
   [junit4]   2> 	        at org.eclipse.jetty.io.nio.SelectorManager$1.run(SelectorManager.java:290)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 	  19) Thread[id=4669, name=qtp522691791-4669 Acceptor0 SslSelectChannelConnector@127.0.0.1:58364, state=BLOCKED, group=TGRP-RecoveryZkTest]
   [junit4]   2> 	        at org.eclipse.jetty.server.nio.SelectChannelConnector.accept(SelectChannelConnector.java:102)
   [junit4]   2> 	        at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:938)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> NOTE: test params are: codec=Lucene46: {id=MockFixedIntBlock(blockSize=1830), a_si=MockVariableIntBlock(baseBlockSize=125), rnd_b=MockFixedIntBlock(blockSize=1830), _version_=PostingsFormat(name=FSTPulsing41), a_t=PostingsFormat(name=FSTPulsing41)}, docValues:{}, sim=DefaultSimilarity, locale=hr_HR, timezone=Pacific/Port_Moresby
   [junit4]   2> NOTE: Linux 3.8.0-37-generic amd64/Oracle Corporation 1.7.0_60-ea (64-bit)/cpus=8,threads=25,free=215069208,total=334983168
   [junit4]   2> NOTE: All tests run in this JVM: [TestNoOpRegenerator, SolrInfoMBeanTest, TestFreeTextSuggestions, TestComplexPhraseQParserPlugin, StatelessScriptUpdateProcessorFactoryTest, SimpleFacetsTest, TestSolrXml, TestFileDictionaryLookup, TestDistribDocBasedVersion, CachingDirectoryFactoryTest, TestFieldTypeResource, UnloadDistributedZkTest, BasicDistributedZkTest, DistributedQueryComponentOptimizationTest, TestStressVersions, TermsComponentTest, SuggesterTest, TestLRUCache, DocValuesTest, TestLuceneMatchVersion, UpdateRequestProcessorFactoryTest, TestCollationFieldDocValues, CSVRequestHandlerTest, BinaryUpdateRequestHandlerTest, JsonLoaderTest, MoreLikeThisHandlerTest, TestGroupingSearch, RangeFacetTest, CoreMergeIndexesAdminHandlerTest, ShardRoutingTest, DistributedQueryComponentCustomSortTest, TestSearcherReuse, TestSurroundQueryParser, IndexSchemaTest, FunctionTest, LukeRequestHandlerTest, ExpressionTest, LoggingHandlerTest, TestFieldSortValues, DocumentBuilderTest, DOMUtilTest, UpdateParamsTest, MBeansHandlerTest, EchoParamsTest, DistributedTermsComponentTest, ResourceLoaderTest, SyncSliceTest, TestLMDirichletSimilarityFactory, TestReplicationHandler, TestManagedResourceStorage, FieldMutatingUpdateProcessorTest, TestRemoteStreaming, TriLevelCompositeIdRoutingTest, TestPostingsSolrHighlighter, TestFunctionQuery, TestSuggestSpellingConverter, ReturnFieldsTest, SpellPossibilityIteratorTest, DistributedQueryElevationComponentTest, StressHdfsTest, TestDocumentBuilder, SampleTest, SliceStateUpdateTest, SliceStateTest, HdfsBasicDistributedZkTest, TestJmxMonitoredMap, PeerSyncTest, LeaderElectionTest, TestFaceting, ClusterStateTest, SynonymTokenizerTest, SpatialFilterTest, ClusterStateUpdateTest, SOLR749Test, TestAddFieldRealTimeGet, TestPerFieldSimilarity, TestDocSet, SchemaVersionSpecificBehaviorTest, BadComponentTest, TestSolrDeletionPolicy1, CacheHeaderTest, SearchHandlerTest, OverseerTest, PolyFieldTest, CircularListTest, TestRealTimeGet, OverseerRolesTest, SolrTestCaseJ4Test, TestCharFilters, ZkCLITest, DeleteInactiveReplicaTest, QueryParsingTest, AliasIntegrationTest, TestSolrXMLSerializer, RecoveryZkTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=RecoveryZkTest -Dtests.seed=CDB667E8A1E7CCF3 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=hr_HR -Dtests.timezone=Pacific/Port_Moresby -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([CDB667E8A1E7CCF3]:0)
   [junit4] Completed on J0 in 7223.32s, 1 test, 2 errors <<< FAILURES!

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

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



Mime
View raw message