lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.7.0_60) - Build # 10438 - Still Failing!
Date Sat, 14 Jun 2014 10:35:16 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/10438/
Java: 64bit/jdk1.7.0_60 -XX:-UseCompressedOops -XX:+UseSerialGC

3 tests failed.
FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.ChaosMonkeySafeLeaderTest

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

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


FAILED:  junit.framework.TestSuite.org.apache.solr.cloud.ChaosMonkeySafeLeaderTest

Error Message:
Captured an uncaught exception in thread: Thread[id=2062, name=RecoveryThread, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]

Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=2062, name=RecoveryThread, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
Caused by: java.lang.AssertionError: liveDocs.count()=12 info.docCount=21 info.getDelCount()=12
	at __randomizedtesting.SeedInfo.seed([AB808A0DF6F26B0]:0)
	at org.apache.lucene.codecs.lucene40.Lucene40LiveDocsFormat.readLiveDocs(Lucene40LiveDocsFormat.java:92)
	at org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:109)
	at org.apache.lucene.index.ReadersAndUpdates.getReader(ReadersAndUpdates.java:143)
	at org.apache.lucene.index.ReadersAndUpdates.getReadOnlyClone(ReadersAndUpdates.java:237)
	at org.apache.lucene.index.StandardDirectoryReader.open(StandardDirectoryReader.java:98)
	at org.apache.lucene.index.IndexWriter.getReader(IndexWriter.java:394)
	at org.apache.lucene.index.StandardDirectoryReader.doOpenIfChanged(StandardDirectoryReader.java:273)
	at org.apache.lucene.index.DirectoryReader.openIfChanged(DirectoryReader.java:251)
	at org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:1471)
	at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:1672)
	at org.apache.solr.handler.SnapPuller.openNewSearcherAndUpdateCommitPoint(SnapPuller.java:673)
	at org.apache.solr.handler.SnapPuller.fetchLatestIndex(SnapPuller.java:493)
	at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:337)
	at org.apache.solr.cloud.RecoveryStrategy.replicate(RecoveryStrategy.java:163)
	at org.apache.solr.cloud.RecoveryStrategy.doRecovery(RecoveryStrategy.java:447)
	at org.apache.solr.cloud.RecoveryStrategy.run(RecoveryStrategy.java:235)


FAILED:  org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.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([AB808A0DF6F26B0]:0)




Build Log:
[...truncated 12065 lines...]
   [junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
   [junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/init-core-data-001
   [junit4]   2> 456095 T1600 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
   [junit4]   2> 456095 T1600 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 456099 T1600 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> 456100 T1600 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   1> client port:0.0.0.0/0.0.0.0:0
   [junit4]   2> 456101 T1601 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 456200 T1600 oasc.ZkTestServer.run start zk server on port:40719
   [junit4]   2> 456202 T1600 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 456214 T1607 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1720156e name:ZooKeeperConnection Watcher:127.0.0.1:40719 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 456214 T1600 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 456215 T1600 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 456221 T1600 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 456223 T1609 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4f3ad690 name:ZooKeeperConnection Watcher:127.0.0.1:40719/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 456224 T1600 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 456224 T1600 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 456228 T1600 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 456232 T1600 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 456236 T1600 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 456239 T1600 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 456240 T1600 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 456246 T1600 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
   [junit4]   2> 456246 T1600 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 456251 T1600 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 456252 T1600 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 456256 T1600 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 456256 T1600 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 456261 T1600 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 456261 T1600 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 456265 T1600 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 456266 T1600 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 456271 T1600 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 456272 T1600 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 456277 T1600 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 456277 T1600 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 456281 T1600 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 456281 T1600 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 456285 T1600 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 456285 T1600 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 456289 T1600 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/core/src/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 456290 T1600 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 456297 T1600 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 456299 T1611 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4b69ccaa name:ZooKeeperConnection Watcher:127.0.0.1:40719/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 456299 T1600 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 456541 T1600 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 456544 T1600 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 456547 T1600 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:56435
   [junit4]   2> 456548 T1600 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 456548 T1600 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 456548 T1600 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-002
   [junit4]   2> 456549 T1600 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-002/'
   [junit4]   2> 456559 T1600 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-002/solr.xml
   [junit4]   2> 456591 T1600 oasc.CoreContainer.<init> New CoreContainer 712337408
   [junit4]   2> 456591 T1600 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-002/]
   [junit4]   2> 456592 T1600 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 456592 T1600 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 456592 T1600 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 456593 T1600 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 456593 T1600 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 456593 T1600 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 456593 T1600 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 456593 T1600 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 456594 T1600 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 456596 T1600 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 456596 T1600 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 456596 T1600 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 456596 T1600 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:40719/solr
   [junit4]   2> 456597 T1600 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 456597 T1600 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 456599 T1622 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7b95ad10 name:ZooKeeperConnection Watcher:127.0.0.1:40719 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 456599 T1600 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 456601 T1600 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 456602 T1624 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@447cd0a2 name:ZooKeeperConnection Watcher:127.0.0.1:40719/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 456602 T1600 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 456603 T1600 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 456606 T1600 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 456609 T1600 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-running
   [junit4]   2> 456611 T1600 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-completed
   [junit4]   2> 456613 T1600 oascc.SolrZkClient.makePath makePath: /overseer/collection-map-failure
   [junit4]   2> 456615 T1600 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 456617 T1600 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56435_
   [junit4]   2> 456618 T1600 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:56435_
   [junit4]   2> 456622 T1600 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 456624 T1600 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 456632 T1600 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:56435_
   [junit4]   2> 456632 T1600 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 456634 T1600 oasc.Overseer.start Overseer (id=91929632144687108-127.0.0.1:56435_-n_0000000000) starting
   [junit4]   2> 456637 T1600 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 456645 T1626 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 456645 T1600 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 456647 T1600 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 456648 T1600 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 456650 T1625 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 456653 T1627 oasc.ZkController.publish publishing core=collection1 state=down collection=control_collection
   [junit4]   2> 456653 T1627 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 456654 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 456654 T1627 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 456656 T1625 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 456656 T1625 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:56435",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:56435_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 456656 T1625 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 456657 T1625 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 456659 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 456660 T1624 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> 457655 T1627 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 457655 T1627 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 457656 T1627 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 457657 T1627 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 457659 T1627 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 457659 T1627 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-002/collection1/'
   [junit4]   2> 457660 T1627 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-002/collection1/lib/.svn/' to classloader
   [junit4]   2> 457661 T1627 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-002/collection1/lib/classes/' to classloader
   [junit4]   2> 457661 T1627 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-002/collection1/lib/README' to classloader
   [junit4]   2> 457719 T1627 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
   [junit4]   2> 457759 T1627 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 457761 T1627 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 457768 T1627 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 458005 T1627 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 458007 T1627 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 458008 T1627 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 458012 T1627 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 458032 T1627 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection control_collection
   [junit4]   2> 458032 T1627 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 458032 T1627 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-002/collection1/, dataDir=./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-001/control/data/
   [junit4]   2> 458033 T1627 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@780e4aa6
   [junit4]   2> 458033 T1627 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-001/control/data
   [junit4]   2> 458033 T1627 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-001/control/data/index/
   [junit4]   2> 458034 T1627 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-001/control/data/index' doesn't exist. Creating new index...
   [junit4]   2> 458034 T1627 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-001/control/data/index
   [junit4]   2> 458035 T1627 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@3b7eb286
   [junit4]   2> 458041 T1627 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-001/control/data/index,segFN=segments_1,generation=1}
   [junit4]   2> 458041 T1627 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 458046 T1627 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 458047 T1627 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 458047 T1627 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 458047 T1627 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 458047 T1627 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 458047 T1627 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 458048 T1627 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 458048 T1627 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 458048 T1627 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 458048 T1627 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 458049 T1627 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 458049 T1627 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 458049 T1627 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 458049 T1627 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 458050 T1627 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 458050 T1627 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 458052 T1627 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 458053 T1627 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 458053 T1627 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 458054 T1627 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=35, maxMergeAtOnceExplicit=36, maxMergedSegmentMB=56.24609375, floorSegmentMB=0.7041015625, forceMergeDeletesPctAllowed=11.408561809168626, segmentsPerTier=19.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4421442274201489
   [junit4]   2> 458055 T1627 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-001/control/data/index,segFN=segments_1,generation=1}
   [junit4]   2> 458055 T1627 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 458055 T1627 oass.SolrIndexSearcher.<init> Opening Searcher@5f500137[collection1] main
   [junit4]   2> 458056 T1627 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 458056 T1627 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 458057 T1627 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 458057 T1627 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 458057 T1627 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 458057 T1627 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 458058 T1627 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 458058 T1627 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 458058 T1627 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 458058 T1627 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 458060 T1628 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5f500137[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 458061 T1627 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 458062 T1631 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:56435 collection:control_collection shard:shard1
   [junit4]   2> 458062 T1600 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 458062 T1600 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 458063 T1631 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 458067 T1600 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 458069 T1633 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2ffad72f name:ZooKeeperConnection Watcher:127.0.0.1:40719/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 458069 T1600 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 458070 T1600 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 458071 T1631 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 458073 T1600 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 458074 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 458074 T1631 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 458074 T1631 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C2833 name=collection1 org.apache.solr.core.SolrCore@dcef2c url=https://127.0.0.1:56435/collection1 node=127.0.0.1:56435_ C2833_STATE=coll:control_collection core:collection1 props:{state=down, base_url=https://127.0.0.1:56435, core=collection1, node_name=127.0.0.1:56435_}
   [junit4]   2> 458074 T1631 C2833 P56435 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:56435/collection1/
   [junit4]   2> 458075 T1631 C2833 P56435 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 458075 T1631 C2833 P56435 oasc.SyncStrategy.syncToMe https://127.0.0.1:56435/collection1/ has no replicas
   [junit4]   2> 458075 T1625 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 458075 T1631 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:56435/collection1/ shard1
   [junit4]   2> 458075 T1631 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 458077 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 458080 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 458083 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 458185 T1633 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> 458185 T1624 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> 458232 T1631 oasc.ZkController.register We are https://127.0.0.1:56435/collection1/ and leader is https://127.0.0.1:56435/collection1/
   [junit4]   2> 458232 T1631 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:56435
   [junit4]   2> 458232 T1631 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 458232 T1631 oasc.ZkController.publish publishing core=collection1 state=active collection=control_collection
   [junit4]   2> 458232 T1631 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 458235 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 458235 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 458235 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 458235 T1631 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 458236 T1625 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 458237 T1625 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:56435",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:56435_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 458239 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 458300 T1600 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 458301 T1600 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 458305 T1600 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 458307 T1600 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:51409
   [junit4]   2> 458310 T1600 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 458310 T1600 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 458311 T1600 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-003
   [junit4]   2> 458311 T1600 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-003/'
   [junit4]   2> 458329 T1600 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-003/solr.xml
   [junit4]   2> 458340 T1624 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> 458340 T1633 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> 458352 T1600 oasc.CoreContainer.<init> New CoreContainer 641499378
   [junit4]   2> 458352 T1600 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-003/]
   [junit4]   2> 458353 T1600 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 458353 T1600 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 458353 T1600 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 458354 T1600 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 458354 T1600 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 458354 T1600 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 458354 T1600 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 458354 T1600 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 458355 T1600 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 458357 T1600 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 458357 T1600 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 458357 T1600 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 458357 T1600 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:40719/solr
   [junit4]   2> 458358 T1600 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 458358 T1600 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 458360 T1644 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3597775f name:ZooKeeperConnection Watcher:127.0.0.1:40719 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 458360 T1600 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 458362 T1600 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 458363 T1646 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4686ba06 name:ZooKeeperConnection Watcher:127.0.0.1:40719/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 458363 T1600 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 458368 T1600 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 459371 T1600 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51409_
   [junit4]   2> 459373 T1600 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51409_
   [junit4]   2> 459377 T1633 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 459377 T1646 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 459377 T1624 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 459387 T1647 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 459387 T1647 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 459389 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 459389 T1647 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 459389 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 459390 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 459392 T1625 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 459394 T1625 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:51409",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:51409_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 459394 T1625 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
   [junit4]   2> 459394 T1625 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 459404 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 459507 T1624 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> 459507 T1633 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> 459507 T1646 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> 460390 T1647 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 460390 T1647 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 460391 T1647 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 460391 T1647 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 460392 T1647 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 460392 T1647 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: './solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-003/collection1/'
   [junit4]   2> 460393 T1647 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-003/collection1/lib/.svn/' to classloader
   [junit4]   2> 460393 T1647 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-003/collection1/lib/classes/' to classloader
   [junit4]   2> 460393 T1647 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-003/collection1/lib/README' to classloader
   [junit4]   2> 460423 T1647 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
   [junit4]   2> 460446 T1647 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 460447 T1647 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 460453 T1647 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 460691 T1647 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 460692 T1647 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 460693 T1647 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 460697 T1647 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 460721 T1647 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 460721 T1647 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 460721 T1647 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-003/collection1/, dataDir=./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-001/jetty1/
   [junit4]   2> 460722 T1647 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@780e4aa6
   [junit4]   2> 460722 T1647 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-001/jetty1
   [junit4]   2> 460723 T1647 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-001/jetty1/index/
   [junit4]   2> 460723 T1647 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-001/jetty1/index' doesn't exist. Creating new index...
   [junit4]   2> 460723 T1647 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-001/jetty1/index
   [junit4]   2> 460724 T1647 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@7fb96a71
   [junit4]   2> 460728 T1647 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-001/jetty1/index,segFN=segments_1,generation=1}
   [junit4]   2> 460728 T1647 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 460732 T1647 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 460732 T1647 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 460732 T1647 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 460733 T1647 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 460733 T1647 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 460733 T1647 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 460733 T1647 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 460734 T1647 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 460734 T1647 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 460734 T1647 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 460735 T1647 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 460735 T1647 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 460735 T1647 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 460735 T1647 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 460736 T1647 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 460736 T1647 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 460738 T1647 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 460740 T1647 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 460740 T1647 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 460741 T1647 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=35, maxMergeAtOnceExplicit=36, maxMergedSegmentMB=56.24609375, floorSegmentMB=0.7041015625, forceMergeDeletesPctAllowed=11.408561809168626, segmentsPerTier=19.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4421442274201489
   [junit4]   2> 460742 T1647 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-001/jetty1/index,segFN=segments_1,generation=1}
   [junit4]   2> 460742 T1647 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 460742 T1647 oass.SolrIndexSearcher.<init> Opening Searcher@137c92df[collection1] main
   [junit4]   2> 460742 T1647 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 460744 T1647 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 460744 T1647 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 460745 T1647 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 460745 T1647 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 460745 T1647 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 460746 T1647 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 460746 T1647 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 460746 T1647 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 460747 T1647 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 460750 T1648 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@137c92df[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 460752 T1647 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 460767 T1651 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:51409 collection:collection1 shard:shard3
   [junit4]   2> 460767 T1600 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 460767 T1600 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 460768 T1651 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 460775 T1651 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard3
   [junit4]   2> 460777 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 460777 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 460777 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 460777 T1651 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 460777 T1651 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C2834 name=collection1 org.apache.solr.core.SolrCore@1afc9331 url=https://127.0.0.1:51409/collection1 node=127.0.0.1:51409_ C2834_STATE=coll:collection1 core:collection1 props:{state=down, base_url=https://127.0.0.1:51409, core=collection1, node_name=127.0.0.1:51409_}
   [junit4]   2> 460777 T1651 C2834 P51409 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:51409/collection1/
   [junit4]   2> 460778 T1651 C2834 P51409 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 460778 T1651 C2834 P51409 oasc.SyncStrategy.syncToMe https://127.0.0.1:51409/collection1/ has no replicas
   [junit4]   2> 460778 T1651 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:51409/collection1/ shard3
   [junit4]   2> 460778 T1651 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
   [junit4]   2> 460778 T1625 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 460781 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 460783 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 460785 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 460891 T1646 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> 460891 T1633 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> 460891 T1624 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> 460934 T1651 oasc.ZkController.register We are https://127.0.0.1:51409/collection1/ and leader is https://127.0.0.1:51409/collection1/
   [junit4]   2> 460934 T1651 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:51409
   [junit4]   2> 460934 T1651 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 460934 T1651 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 460934 T1651 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 460936 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 460936 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 460936 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 460937 T1651 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 460938 T1625 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 460938 T1625 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:51409",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:51409_",
   [junit4]   2> 	  "shard":"shard3",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 460941 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 461008 T1600 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 461008 T1600 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 461014 T1600 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 461015 T1600 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:43471
   [junit4]   2> 461019 T1600 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 461019 T1600 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 461019 T1600 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-004
   [junit4]   2> 461019 T1600 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-004/'
   [junit4]   2> 461033 T1600 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-004/solr.xml
   [junit4]   2> 461043 T1624 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> 461043 T1633 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> 461043 T1646 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> 461056 T1600 oasc.CoreContainer.<init> New CoreContainer 481810274
   [junit4]   2> 461056 T1600 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-004/]
   [junit4]   2> 461057 T1600 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 461057 T1600 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 461057 T1600 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 461057 T1600 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 461058 T1600 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 461058 T1600 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 461058 T1600 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 461058 T1600 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 461058 T1600 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 461060 T1600 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 461061 T1600 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 461061 T1600 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 461061 T1600 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:40719/solr
   [junit4]   2> 461061 T1600 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 461062 T1600 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 461064 T1662 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@51613fbc name:ZooKeeperConnection Watcher:127.0.0.1:40719 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 461065 T1600 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 461068 T1600 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 461070 T1664 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@24f30fc1 name:ZooKeeperConnection Watcher:127.0.0.1:40719/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 461070 T1600 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 461083 T1600 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 462089 T1600 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43471_
   [junit4]   2> 462091 T1600 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:43471_
   [junit4]   2> 462096 T1633 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 462096 T1646 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 462097 T1664 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 462096 T1624 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 462106 T1665 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 462107 T1665 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 462112 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 462112 T1665 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 462113 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 462113 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 462116 T1625 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 462118 T1625 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:43471",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:43471_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 462118 T1625 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 462118 T1625 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 462123 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 462227 T1633 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> 462227 T1646 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> 462227 T1664 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> 462227 T1624 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> 463113 T1665 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 463113 T1665 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 463114 T1665 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 463114 T1665 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 463115 T1665 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 463115 T1665 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-004/collection1/'
   [junit4]   2> 463116 T1665 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-004/collection1/lib/.svn/' to classloader
   [junit4]   2> 463116 T1665 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-004/collection1/lib/classes/' to classloader
   [junit4]   2> 463116 T1665 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-004/collection1/lib/README' to classloader
   [junit4]   2> 463155 T1665 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
   [junit4]   2> 463178 T1665 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 463179 T1665 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 463185 T1665 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 463396 T1665 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 463397 T1665 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 463398 T1665 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 463401 T1665 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 463419 T1665 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from collection collection1
   [junit4]   2> 463420 T1665 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 463420 T1665 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-004/collection1/, dataDir=./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-001/jetty2/
   [junit4]   2> 463420 T1665 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@780e4aa6
   [junit4]   2> 463420 T1665 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-001/jetty2
   [junit4]   2> 463421 T1665 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-001/jetty2/index/
   [junit4]   2> 463421 T1665 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-001/jetty2/index' doesn't exist. Creating new index...
   [junit4]   2> 463421 T1665 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-001/jetty2/index
   [junit4]   2> 463422 T1665 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.MockRandomMergePolicy: org.apache.lucene.index.MockRandomMergePolicy@3fc713df
   [junit4]   2> 463426 T1665 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-001/jetty2/index,segFN=segments_1,generation=1}
   [junit4]   2> 463426 T1665 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 463430 T1665 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 463430 T1665 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 463430 T1665 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 463430 T1665 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 463430 T1665 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 463431 T1665 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 463431 T1665 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 463431 T1665 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 463431 T1665 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 463432 T1665 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 463432 T1665 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 463432 T1665 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 463432 T1665 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 463433 T1665 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 463433 T1665 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 463434 T1665 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 463436 T1665 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 463437 T1665 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 463438 T1665 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 463438 T1665 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=35, maxMergeAtOnceExplicit=36, maxMergedSegmentMB=56.24609375, floorSegmentMB=0.7041015625, forceMergeDeletesPctAllowed=11.408561809168626, segmentsPerTier=19.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.4421442274201489
   [junit4]   2> 463439 T1665 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-001/jetty2/index,segFN=segments_1,generation=1}
   [junit4]   2> 463439 T1665 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 463440 T1665 oass.SolrIndexSearcher.<init> Opening Searcher@5dd6e0a0[collection1] main
   [junit4]   2> 463440 T1665 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 463441 T1665 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 463441 T1665 oasr.ManagedResourceStorage.newStorageIO Setting up ZooKeeper-based storage for the RestManager with znodeBase: /configs/conf1
   [junit4]   2> 463442 T1665 oasr.ManagedResourceStorage$ZooKeeperStorageIO.configure Configured ZooKeeperStorageIO with znodeBase: /configs/conf1
   [junit4]   2> 463442 T1665 oasr.RestManager.init Initializing RestManager with initArgs: {}
   [junit4]   2> 463442 T1665 oasr.ManagedResourceStorage.load Reading _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 463442 T1665 oasr.ManagedResourceStorage$ZooKeeperStorageIO.openInputStream No data found for znode /configs/conf1/_rest_managed.json
   [junit4]   2> 463443 T1665 oasr.ManagedResourceStorage.load Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/conf1
   [junit4]   2> 463443 T1665 oasr.ManagedResource.notifyObserversDuringInit WARN No registered observers for /rest/managed
   [junit4]   2> 463443 T1665 oasr.RestManager.init Initializing 0 registered ManagedResources
   [junit4]   2> 463445 T1666 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5dd6e0a0[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 463447 T1665 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 463448 T1669 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:43471 collection:collection1 shard:shard1
   [junit4]   2> 463448 T1600 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
   [junit4]   2> 463448 T1600 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 463449 T1669 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
   [junit4]   2> 463455 T1669 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 463456 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 463456 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 463457 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 463457 T1669 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 463457 T1669 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C2835 name=collection1 org.apache.solr.core.SolrCore@30ee6cff url=https://127.0.0.1:43471/collection1 node=127.0.0.1:43471_ C2835_STATE=coll:collection1 core:collection1 props:{state=down, base_url=https://127.0.0.1:43471, core=collection1, node_name=127.0.0.1:43471_}
   [junit4]   2> 463457 T1669 C2835 P43471 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:43471/collection1/
   [junit4]   2> 463457 T1669 C2835 P43471 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 463457 T1669 C2835 P43471 oasc.SyncStrategy.syncToMe https://127.0.0.1:43471/collection1/ has no replicas
   [junit4]   2> 463457 T1669 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:43471/collection1/ shard1
   [junit4]   2> 463458 T1625 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 463458 T1669 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
   [junit4]   2> 463460 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 463462 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 463464 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 463569 T1633 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> 463569 T1664 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> 463569 T1646 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> 463569 T1624 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> 463612 T1669 oasc.ZkController.register We are https://127.0.0.1:43471/collection1/ and leader is https://127.0.0.1:43471/collection1/
   [junit4]   2> 463613 T1669 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:43471
   [junit4]   2> 463613 T1669 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 463613 T1669 oasc.ZkController.publish publishing core=collection1 state=active collection=collection1
   [junit4]   2> 463613 T1669 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 463615 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 463615 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 463615 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 463615 T1669 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 463616 T1625 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 463617 T1625 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"active",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:43471",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:43471_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 463619 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 463668 T1600 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
   [junit4]   2> 463668 T1600 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 463671 T1600 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 463672 T1600 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:37210
   [junit4]   2> 463674 T1600 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 463674 T1600 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 463674 T1600 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-005
   [junit4]   2> 463675 T1600 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-005/'
   [junit4]   2> 463685 T1600 oasc.ConfigSolr.fromFile Loading container configuration from /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-005/solr.xml
   [junit4]   2> 463717 T1600 oasc.CoreContainer.<init> New CoreContainer 1968806121
   [junit4]   2> 463718 T1600 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-005/]
   [junit4]   2> 463718 T1600 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 463719 T1600 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 463719 T1600 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 463719 T1600 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 463719 T1600 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 463719 T1600 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 463720 T1600 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 463720 T1600 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 463720 T1600 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 463721 T1646 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> 463721 T1624 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> 463721 T1633 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> 463721 T1664 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> 463723 T1600 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 463723 T1600 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 463723 T1600 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 463724 T1600 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:40719/solr
   [junit4]   2> 463724 T1600 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 463725 T1600 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 463726 T1680 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@255dc242 name:ZooKeeperConnection Watcher:127.0.0.1:40719 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 463726 T1600 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 463728 T1600 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 463729 T1682 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11099485 name:ZooKeeperConnection Watcher:127.0.0.1:40719/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 463729 T1600 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 463737 T1600 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 464740 T1600 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:37210_
   [junit4]   2> 464741 T1600 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:37210_
   [junit4]   2> 464743 T1646 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 464743 T1682 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 464743 T1624 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 464743 T1633 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 464743 T1664 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 464748 T1683 oasc.ZkController.publish publishing core=collection1 state=down collection=collection1
   [junit4]   2> 464749 T1683 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 464750 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 464750 T1683 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 464750 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 464751 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 464752 T1625 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 464752 T1625 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
   [junit4]   2> 	  "operation":"state",
   [junit4]   2> 	  "state":"down",
   [junit4]   2> 	  "base_url":"https://127.0.0.1:37210",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:37210_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 464752 T1625 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 464753 T1625 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 464755 T1624 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 464856 T1624 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 464856 T1646 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 464856 T1664 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 464856 T1633 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 464856 T1682 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
   [junit4]   2> 465751 T1683 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 465751 T1683 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 465753 T1683 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 465753 T1683 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 465754 T1683 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 465755 T1683 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '../../../../../../../../../../mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-005/collection1/'
   [junit4]   2> 465756 T1683 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-005/collection1/lib/.svn/' to classloader
   [junit4]   2> 465756 T1683 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-005/collection1/lib/classes/' to classloader
   [junit4]   2> 465757 T1683 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/solr.cloud.ChaosMonkeySafeLeaderTest-AB808A0DF6F26B0-001/tempDir-005/collection1/lib/README' to classloader
   [junit4]   2> 465798 T1683 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_4_9
   [junit4]   2> 465830 T1683 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2>

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

wait(Object.java:503)
   [junit4]   2> 	        at org.apache.solr.core.CloserThread.run(CoreContainer.java:944)
   [junit4]   2> 	  85) Thread[id=2323, name=qtp39637143-2323 Acceptor0 SslSelectChannelConnector@127.0.0.1:36038, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:956)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 	  86) Thread[id=2662, name=Thread-1332, state=WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at java.lang.Object.wait(Native Method)
   [junit4]   2> 	        at java.lang.Object.wait(Object.java:503)
   [junit4]   2> 	        at org.apache.solr.core.CloserThread.run(CoreContainer.java:944)
   [junit4]   2> 	  87) Thread[id=2675, name=qtp1089490924-2675 Acceptor1 SslSelectChannelConnector@127.0.0.1:59783, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]   2> 	        at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:956)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
   [junit4]   2> 	        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
   [junit4]   2> 	        at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 	  88) Thread[id=2762, name=Thread-922-SendThread(127.0.0.1:40719), state=TIMED_WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
   [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> 	  89) Thread[id=2792, name=searcherExecutor-1358-thread-1, state=WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
   [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:745)
   [junit4]   2> 7681936 T2785 oaz.ClientCnxn$SendThread.run WARN Session 0x14699836c510065 for server null, unexpected error, closing socket connection and attempting reconnect java.net.ConnectException: Connection refused
   [junit4]   2> 	at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
   [junit4]   2> 	at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:739)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1081)
   [junit4]   2> 
   [junit4]   2> 7681937 T2705 oaz.ClientCnxn$SendThread.run WARN Session 0x14699836c51005f for server null, unexpected error, closing socket connection and attempting reconnect java.net.ConnectException: Connection refused
   [junit4]   2> 	at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
   [junit4]   2> 	at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:739)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:361)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1081)
   [junit4]   2> 
   [junit4]   2> NOTE: test params are: codec=Lucene3x, sim=DefaultSimilarity, locale=da_DK, timezone=Etc/GMT+5
   [junit4]   2> NOTE: Linux 3.8.0-41-generic amd64/Oracle Corporation 1.7.0_60 (64-bit)/cpus=8,threads=106,free=40217984,total=294178816
   [junit4]   2> NOTE: All tests run in this JVM: [PingRequestHandlerTest, SolrTestCaseJ4Test, TestAtomicUpdateErrorCases, TestCursorMarkWithoutUniqueKey, SuggesterWFSTTest, ZkSolrClientTest, HdfsDirectoryTest, OutputWriterTest, TestQueryTypes, TestSchemaSimilarityResource, TestIndexSearcher, OpenCloseCoreStressTest, DocumentAnalysisRequestHandlerTest, TestCodecSupport, SuggesterTSTTest, CoreContainerCoreInitFailuresTest, TimeZoneUtilsTest, TestUpdate, TestNonNRTOpen, SuggestComponentTest, TestNoOpRegenerator, StandardRequestHandlerTest, PrimUtilsTest, TestRandomFaceting, JSONWriterTest, TestPhraseSuggestions, HdfsRecoveryZkTest, TestStressReorder, CurrencyFieldOpenExchangeTest, DefaultValueUpdateProcessorTest, TestBinaryField, TestHighlightDedupGrouping, AddBlockUpdateTest, NotRequiredUniqueKeyTest, CoreAdminRequestStatusTest, DirectSolrConnectionTest, TestAnalyzedSuggestions, OpenExchangeRatesOrgProviderTest, TestArbitraryIndexDir, SSLMigrationTest, TestPartialUpdateDeduplication, TestSolrQueryParserResource, TestFiltering, TestSchemaNameResource, DistribCursorPagingTest, FileUtilsTest, TestUniqueKeyFieldResource, ConvertedLegacyTest, TestOmitPositions, TestFieldResource, TestRequestStatusCollectionAPI, HdfsBasicDistributedZk2Test, TestSolrJ, TestSolr4Spatial, UniqFieldsUpdateProcessorFactoryTest, DistributedQueryComponentCustomSortTest, PreAnalyzedFieldTest, ShardRoutingCustomTest, TestRTGBase, TestCloudInspectUtil, PluginInfoTest, ChaosMonkeyNothingIsSafeTest, DocExpirationUpdateProcessorFactoryTest, ChaosMonkeySafeLeaderTest]
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=ChaosMonkeySafeLeaderTest -Dtests.seed=AB808A0DF6F26B0 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=da_DK -Dtests.timezone=Etc/GMT+5 -Dtests.file.encoding=ISO-8859-1
   [junit4] ERROR   0.00s J1 | ChaosMonkeySafeLeaderTest (suite) <<<
   [junit4]    > Throwable #1: java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([AB808A0DF6F26B0]:0)Throwable #2: com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=2062, name=RecoveryThread, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
   [junit4]    > Caused by: java.lang.AssertionError: liveDocs.count()=12 info.docCount=21 info.getDelCount()=12
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([AB808A0DF6F26B0]:0)
   [junit4]    > 	at org.apache.lucene.codecs.lucene40.Lucene40LiveDocsFormat.readLiveDocs(Lucene40LiveDocsFormat.java:92)
   [junit4]    > 	at org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:109)
   [junit4]    > 	at org.apache.lucene.index.ReadersAndUpdates.getReader(ReadersAndUpdates.java:143)
   [junit4]    > 	at org.apache.lucene.index.ReadersAndUpdates.getReadOnlyClone(ReadersAndUpdates.java:237)
   [junit4]    > 	at org.apache.lucene.index.StandardDirectoryReader.open(StandardDirectoryReader.java:98)
   [junit4]    > 	at org.apache.lucene.index.IndexWriter.getReader(IndexWriter.java:394)
   [junit4]    > 	at org.apache.lucene.index.StandardDirectoryReader.doOpenIfChanged(StandardDirectoryReader.java:273)
   [junit4]    > 	at org.apache.lucene.index.DirectoryReader.openIfChanged(DirectoryReader.java:251)
   [junit4]    > 	at org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:1471)
   [junit4]    > 	at org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:1672)
   [junit4]    > 	at org.apache.solr.handler.SnapPuller.openNewSearcherAndUpdateCommitPoint(SnapPuller.java:673)
   [junit4]    > 	at org.apache.solr.handler.SnapPuller.fetchLatestIndex(SnapPuller.java:493)
   [junit4]    > 	at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:337)
   [junit4]    > 	at org.apache.solr.cloud.RecoveryStrategy.replicate(RecoveryStrategy.java:163)
   [junit4]    > 	at org.apache.solr.cloud.RecoveryStrategy.doRecovery(RecoveryStrategy.java:447)
   [junit4]    > 	at org.apache.solr.cloud.RecoveryStrategy.run(RecoveryStrategy.java:235)
   [junit4] Completed on J1 in 7225.93s, 1 test, 3 errors <<< FAILURES!

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

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



Mime
View raw message