You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2014/02/21 00:21:54 UTC

[JENKINS] Lucene-Solr-4.x-Windows (32bit/jdk1.7.0_60-ea-b04) - Build # 3725 - Failure!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/3725/
Java: 32bit/jdk1.7.0_60-ea-b04 -client -XX:+UseParallelGC

1 tests failed.
REGRESSION:  org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.testDistribSearch

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

Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=6219, name=RecoveryThread, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
	at __randomizedtesting.SeedInfo.seed([5ACA007ACBB89B41:DB2C8E62BCE7FB7D]:0)
Caused by: java.lang.AssertionError: file _0.si does not exist
	at __randomizedtesting.SeedInfo.seed([5ACA007ACBB89B41]:0)
	at org.apache.lucene.index.IndexWriter.filesExist(IndexWriter.java:4363)
	at org.apache.lucene.index.IndexWriter.startCommit(IndexWriter.java:4429)
	at org.apache.lucene.index.IndexWriter.prepareCommitInternal(IndexWriter.java:2926)
	at org.apache.lucene.index.IndexWriter.commitInternal(IndexWriter.java:3022)
	at org.apache.lucene.index.IndexWriter.commit(IndexWriter.java:2989)
	at org.apache.solr.update.DirectUpdateHandler2.commit(DirectUpdateHandler2.java:578)
	at org.apache.solr.cloud.RecoveryStrategy.doRecovery(RecoveryStrategy.java:396)
	at org.apache.solr.cloud.RecoveryStrategy.run(RecoveryStrategy.java:247)




Build Log:
[...truncated 10684 lines...]
   [junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
   [junit4]   2> 1492384 T5878 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (true)
   [junit4]   2> 1492384 T5878 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 1492394 T5878 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
   [junit4]   2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-ChaosMonkeySafeLeaderTest-1392936937971
   [junit4]   2> 1492399 T5878 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 1492400 T5879 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1492504 T5878 oasc.ZkTestServer.run start zk server on port:49178
   [junit4]   2> 1492507 T5878 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1492517 T5885 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@297299 name:ZooKeeperConnection Watcher:127.0.0.1:49178 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1492517 T5878 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1492517 T5878 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1492525 T5880 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1445182ea030000, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 1492534 T5878 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1492550 T5887 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@51ac5f name:ZooKeeperConnection Watcher:127.0.0.1:49178/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1492552 T5878 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1492552 T5878 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 1492560 T5878 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 1492567 T5878 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 1492573 T5878 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 1492579 T5878 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
   [junit4]   2> 1492580 T5878 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 1492590 T5878 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\schema15.xml to /configs/conf1/schema.xml
   [junit4]   2> 1492590 T5878 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 1492598 T5878 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig.snippet.randomindexconfig.xml to /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1492600 T5878 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1492605 T5878 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
   [junit4]   2> 1492605 T5878 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 1492612 T5878 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
   [junit4]   2> 1492612 T5878 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 1492620 T5878 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
   [junit4]   2> 1492620 T5878 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 1492628 T5878 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\enumsConfig.xml to /configs/conf1/enumsConfig.xml
   [junit4]   2> 1492629 T5878 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 1492635 T5878 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1492636 T5878 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1492641 T5878 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1492642 T5878 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1492648 T5878 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
   [junit4]   2> 1492649 T5878 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 1492656 T5878 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
   [junit4]   2> 1492657 T5878 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 1492666 T5878 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1492670 T5889 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b7dcb6 name:ZooKeeperConnection Watcher:127.0.0.1:49178/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1492670 T5878 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1493257 T5878 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1493268 T5878 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 1493273 T5878 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:49188
   [junit4]   2> 1493278 T5878 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1493279 T5878 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1493279 T5878 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392936938248
   [junit4]   2> 1493279 T5878 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392936938248\'
   [junit4]   2> 1493314 T5878 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392936938248\solr.xml
   [junit4]   2> 1493378 T5878 oasc.CoreContainer.<init> New CoreContainer 10520051
   [junit4]   2> 1493379 T5878 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392936938248\]
   [junit4]   2> 1493380 T5878 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1493381 T5878 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1493381 T5878 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1493381 T5878 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1493382 T5878 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1493382 T5878 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1493382 T5878 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1493383 T5878 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1493383 T5878 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1493395 T5878 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1493396 T5878 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1493396 T5878 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1493397 T5878 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49178/solr
   [junit4]   2> 1493397 T5878 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1493399 T5878 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1493407 T5900 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8e56fd name:ZooKeeperConnection Watcher:127.0.0.1:49178 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1493408 T5878 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1493411 T5880 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1445182ea030003, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 1493413 T5878 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1493416 T5902 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@190b8ea name:ZooKeeperConnection Watcher:127.0.0.1:49178/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1493417 T5878 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1493420 T5878 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1493427 T5878 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1493440 T5878 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1493444 T5878 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49188_
   [junit4]   2> 1493446 T5878 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49188_
   [junit4]   2> 1493453 T5878 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1493459 T5878 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1493468 T5878 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:49188_
   [junit4]   2> 1493468 T5878 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1493474 T5878 oasc.Overseer.start Overseer (id=91287515167916036-127.0.0.1:49188_-n_0000000000) starting
   [junit4]   2> 1493480 T5878 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1493489 T5878 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1493490 T5904 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1493492 T5904 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 1493496 T5878 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1493500 T5878 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1493506 T5903 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1493514 T5905 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1493514 T5905 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1493517 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1493517 T5905 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1493520 T5903 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1493521 T5903 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:49188",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49188_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1493521 T5903 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 1493521 T5903 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1493530 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1493532 T5902 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> 1494553 T5905 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1494553 T5905 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392936938248\collection1
   [junit4]   2> 1494553 T5905 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 1494556 T5905 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1494556 T5905 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 1494558 T5905 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1494558 T5905 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392936938248\collection1\'
   [junit4]   2> 1494560 T5905 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392936938248/collection1/lib/classes/' to classloader
   [junit4]   2> 1494562 T5905 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392936938248/collection1/lib/README' to classloader
   [junit4]   2> 1494656 T5905 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
   [junit4]   2> 1494737 T5905 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1494740 T5905 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1494761 T5905 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1495418 T5905 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1495423 T5905 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1495427 T5905 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1495438 T5905 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1495504 T5905 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 1495505 T5905 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392936938248\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968/control/data\
   [junit4]   2> 1495505 T5905 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@f000b2
   [junit4]   2> 1495505 T5905 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968\control\data
   [junit4]   2> 1495508 T5905 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968/control/data\index/
   [junit4]   2> 1495508 T5905 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968\control\data\index' doesn't exist. Creating new index...
   [junit4]   2> 1495510 T5905 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968\control\data\index
   [junit4]   2> 1495510 T5905 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=6, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8530789027716157]
   [junit4]   2> 1495520 T5905 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968\control\data\index,segFN=segments_1,generation=1}
   [junit4]   2> 1495520 T5905 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1495524 T5905 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1495524 T5905 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1495524 T5905 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1495524 T5905 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1495524 T5905 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1495524 T5905 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1495524 T5905 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1495525 T5905 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1495525 T5905 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1495526 T5905 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1495526 T5905 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1495526 T5905 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1495526 T5905 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1495528 T5905 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1495528 T5905 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1495529 T5905 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1495536 T5905 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1495543 T5905 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1495543 T5905 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1495544 T5905 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=40, maxMergeAtOnceExplicit=31, maxMergedSegmentMB=51.8212890625, floorSegmentMB=2.19921875, forceMergeDeletesPctAllowed=22.949428288099448, segmentsPerTier=13.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 1495544 T5905 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968\control\data\index,segFN=segments_1,generation=1}
   [junit4]   2> 1495544 T5905 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1495544 T5905 oass.SolrIndexSearcher.<init> Opening Searcher@3ef04a[collection1] main
   [junit4]   2> 1495550 T5906 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3ef04a[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1495550 T5905 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1495553 T5878 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 1495554 T5878 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1495560 T5909 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:49188 collection:control_collection shard:shard1
   [junit4]   2> 1495563 T5909 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 1495569 T5878 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1495574 T5911 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15f67c7 name:ZooKeeperConnection Watcher:127.0.0.1:49178/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1495575 T5878 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1495578 T5878 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1495585 T5878 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 1495587 T5909 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1495594 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1495596 T5909 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1495596 T5909 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C1160 name=collection1 org.apache.solr.core.SolrCore@1a22417 url=https://127.0.0.1:49188/collection1 node=127.0.0.1:49188_ C1160_STATE=coll:control_collection core:collection1 props:{state=down, base_url=https://127.0.0.1:49188, core=collection1, node_name=127.0.0.1:49188_}
   [junit4]   2> 1495597 T5909 C1160 P49188 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:49188/collection1/
   [junit4]   2> 1495597 T5909 C1160 P49188 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1495597 T5909 C1160 P49188 oasc.SyncStrategy.syncToMe https://127.0.0.1:49188/collection1/ has no replicas
   [junit4]   2> 1495597 T5909 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:49188/collection1/ shard1
   [junit4]   2> 1495597 T5909 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 1495603 T5903 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1495617 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1495620 T5911 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> 1495621 T5902 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> 1495631 T5903 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1495641 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1495752 T5902 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> 1495753 T5911 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> 1495785 T5909 oasc.ZkController.register We are https://127.0.0.1:49188/collection1/ and leader is https://127.0.0.1:49188/collection1/
   [junit4]   2> 1495785 T5909 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:49188
   [junit4]   2> 1495785 T5909 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1495785 T5909 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1495785 T5909 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1495793 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1495794 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1495794 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1495797 T5909 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1495801 T5903 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1495803 T5903 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:49188",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49188_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 1495812 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1495924 T5902 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> 1495924 T5911 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> 1496179 T5878 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 1496180 T5878 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1496193 T5878 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 1496195 T5878 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:49200
   [junit4]   2> 1496201 T5878 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1496201 T5878 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1496201 T5878 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392936941160
   [junit4]   2> 1496201 T5878 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392936941160\'
   [junit4]   2> 1496239 T5878 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392936941160\solr.xml
   [junit4]   2> 1496300 T5878 oasc.CoreContainer.<init> New CoreContainer 19745934
   [junit4]   2> 1496300 T5878 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392936941160\]
   [junit4]   2> 1496302 T5878 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1496302 T5878 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1496302 T5878 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1496302 T5878 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1496302 T5878 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1496302 T5878 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1496304 T5878 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1496304 T5878 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1496304 T5878 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1496315 T5878 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1496315 T5878 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1496315 T5878 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1496315 T5878 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49178/solr
   [junit4]   2> 1496318 T5878 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1496321 T5878 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1496327 T5922 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1452f3e name:ZooKeeperConnection Watcher:127.0.0.1:49178 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1496327 T5878 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1496330 T5880 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1445182ea030006, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 1496332 T5878 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1496335 T5924 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1731ca8 name:ZooKeeperConnection Watcher:127.0.0.1:49178/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1496335 T5878 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1496344 T5878 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1497385 T5878 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49200_
   [junit4]   2> 1497388 T5878 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49200_
   [junit4]   2> 1497396 T5924 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1497397 T5911 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1497397 T5902 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1497412 T5925 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1497413 T5925 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1497415 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1497416 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1497416 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1497415 T5925 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1497419 T5903 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1497420 T5903 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:49200",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49200_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1497420 T5903 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
   [junit4]   2> 1497420 T5903 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 1497427 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1497430 T5924 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> 1497430 T5902 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> 1497431 T5911 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> 1498452 T5925 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1498452 T5925 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392936941160\collection1
   [junit4]   2> 1498453 T5925 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1498454 T5925 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1498455 T5925 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1498457 T5925 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1498457 T5925 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392936941160\collection1\'
   [junit4]   2> 1498459 T5925 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392936941160/collection1/lib/classes/' to classloader
   [junit4]   2> 1498462 T5925 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392936941160/collection1/lib/README' to classloader
   [junit4]   2> 1498560 T5925 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
   [junit4]   2> 1498626 T5925 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1498630 T5925 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1498651 T5925 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1499130 T5925 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1499133 T5925 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1499136 T5925 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1499142 T5925 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1499192 T5925 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 1499193 T5925 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392936941160\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968/jetty1\
   [junit4]   2> 1499193 T5925 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@f000b2
   [junit4]   2> 1499193 T5925 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968\jetty1
   [junit4]   2> 1499193 T5925 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968/jetty1\index/
   [junit4]   2> 1499196 T5925 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968\jetty1\index' doesn't exist. Creating new index...
   [junit4]   2> 1499197 T5925 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968\jetty1\index
   [junit4]   2> 1499198 T5925 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=6, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8530789027716157]
   [junit4]   2> 1499206 T5925 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968\jetty1\index,segFN=segments_1,generation=1}
   [junit4]   2> 1499206 T5925 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1499210 T5925 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1499211 T5925 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1499211 T5925 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1499211 T5925 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1499212 T5925 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1499212 T5925 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1499213 T5925 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1499213 T5925 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1499213 T5925 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1499214 T5925 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1499215 T5925 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1499215 T5925 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1499216 T5925 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1499216 T5925 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1499217 T5925 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1499218 T5925 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1499228 T5925 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1499233 T5925 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1499233 T5925 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1499236 T5925 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=40, maxMergeAtOnceExplicit=31, maxMergedSegmentMB=51.8212890625, floorSegmentMB=2.19921875, forceMergeDeletesPctAllowed=22.949428288099448, segmentsPerTier=13.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 1499236 T5925 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968\jetty1\index,segFN=segments_1,generation=1}
   [junit4]   2> 1499236 T5925 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1499238 T5925 oass.SolrIndexSearcher.<init> Opening Searcher@10bc4ee[collection1] main
   [junit4]   2> 1499247 T5926 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@10bc4ee[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1499250 T5925 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1499252 T5878 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 1499253 T5878 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1499252 T5929 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:49200 collection:collection1 shard:shard2
   [junit4]   2> 1499257 T5929 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 1499293 T5929 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 1499300 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1499302 T5929 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1499302 T5929 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C1161 name=collection1 org.apache.solr.core.SolrCore@14aef98 url=https://127.0.0.1:49200/collection1 node=127.0.0.1:49200_ C1161_STATE=coll:collection1 core:collection1 props:{state=down, base_url=https://127.0.0.1:49200, core=collection1, node_name=127.0.0.1:49200_}
   [junit4]   2> 1499302 T5929 C1161 P49200 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:49200/collection1/
   [junit4]   2> 1499302 T5929 C1161 P49200 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1499302 T5929 C1161 P49200 oasc.SyncStrategy.syncToMe https://127.0.0.1:49200/collection1/ has no replicas
   [junit4]   2> 1499304 T5929 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:49200/collection1/ shard2
   [junit4]   2> 1499304 T5929 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 1499308 T5903 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1499324 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1499327 T5902 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> 1499328 T5911 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> 1499329 T5924 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> 1499347 T5903 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1499357 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1499469 T5924 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> 1499471 T5902 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> 1499472 T5911 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> 1499497 T5929 oasc.ZkController.register We are https://127.0.0.1:49200/collection1/ and leader is https://127.0.0.1:49200/collection1/
   [junit4]   2> 1499497 T5929 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:49200
   [junit4]   2> 1499497 T5929 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1499497 T5929 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1499497 T5929 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1499501 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1499501 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1499501 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1499504 T5929 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1499510 T5903 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1499511 T5903 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:49200",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49200_",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 1499519 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1499629 T5924 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> 1499630 T5902 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> 1499630 T5911 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> 1499879 T5878 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 1499880 T5878 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1499890 T5878 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 1499892 T5878 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:49209
   [junit4]   2> 1499898 T5878 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1499898 T5878 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1499898 T5878 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392936944832
   [junit4]   2> 1499898 T5878 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392936944832\'
   [junit4]   2> 1499949 T5878 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392936944832\solr.xml
   [junit4]   2> 1500014 T5878 oasc.CoreContainer.<init> New CoreContainer 2570227
   [junit4]   2> 1500015 T5878 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392936944832\]
   [junit4]   2> 1500016 T5878 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1500016 T5878 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1500017 T5878 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1500017 T5878 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1500018 T5878 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1500018 T5878 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1500018 T5878 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1500019 T5878 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1500019 T5878 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1500030 T5878 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1500031 T5878 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1500031 T5878 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1500032 T5878 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49178/solr
   [junit4]   2> 1500032 T5878 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1500035 T5878 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1500040 T5940 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1edc172 name:ZooKeeperConnection Watcher:127.0.0.1:49178 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1500041 T5878 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1500046 T5878 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1500050 T5942 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@471476 name:ZooKeeperConnection Watcher:127.0.0.1:49178/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1500050 T5878 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1500059 T5878 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1501003 T5878 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49209_
   [junit4]   2> 1501005 T5878 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49209_
   [junit4]   2> 1501008 T5942 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1501008 T5911 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1501009 T5924 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1501009 T5902 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1501018 T5943 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1501018 T5943 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1501020 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1501021 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1501021 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1501020 T5943 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1501023 T5903 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1501024 T5903 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:49209",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49209_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1501024 T5903 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 1501024 T5903 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 1501029 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1501126 T5942 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> 1501127 T5911 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> 1501127 T5902 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> 1501126 T5924 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> 1501953 T5943 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1501953 T5943 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392936944832\collection1
   [junit4]   2> 1501953 T5943 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1501956 T5943 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1501956 T5943 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1501958 T5943 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1501958 T5943 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392936944832\collection1\'
   [junit4]   2> 1501958 T5943 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392936944832/collection1/lib/classes/' to classloader
   [junit4]   2> 1501960 T5943 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392936944832/collection1/lib/README' to classloader
   [junit4]   2> 1502028 T5943 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
   [junit4]   2> 1502076 T5943 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1502079 T5943 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1502090 T5943 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1502505 T5943 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1502507 T5943 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1502509 T5943 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1502515 T5943 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1502555 T5943 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 1502556 T5943 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392936944832\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968/jetty2\
   [junit4]   2> 1502556 T5943 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@f000b2
   [junit4]   2> 1502556 T5943 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968\jetty2
   [junit4]   2> 1502558 T5943 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968/jetty2\index/
   [junit4]   2> 1502558 T5943 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968\jetty2\index' doesn't exist. Creating new index...
   [junit4]   2> 1502558 T5943 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968\jetty2\index
   [junit4]   2> 1502560 T5943 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=6, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8530789027716157]
   [junit4]   2> 1502566 T5943 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968\jetty2\index,segFN=segments_1,generation=1}
   [junit4]   2> 1502566 T5943 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1502569 T5943 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1502569 T5943 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1502570 T5943 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1502570 T5943 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1502570 T5943 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1502570 T5943 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1502572 T5943 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1502572 T5943 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1502572 T5943 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1502573 T5943 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1502574 T5943 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1502574 T5943 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1502574 T5943 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1502575 T5943 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1502575 T5943 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1502576 T5943 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1502585 T5943 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1502589 T5943 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1502589 T5943 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1502590 T5943 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=40, maxMergeAtOnceExplicit=31, maxMergedSegmentMB=51.8212890625, floorSegmentMB=2.19921875, forceMergeDeletesPctAllowed=22.949428288099448, segmentsPerTier=13.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 1502590 T5943 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968\jetty2\index,segFN=segments_1,generation=1}
   [junit4]   2> 1502590 T5943 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1502590 T5943 oass.SolrIndexSearcher.<init> Opening Searcher@1e1ffb7[collection1] main
   [junit4]   2> 1502597 T5944 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1e1ffb7[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1502599 T5943 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1502600 T5878 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 1502601 T5878 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1502601 T5947 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:49209 collection:collection1 shard:shard3
   [junit4]   2> 1502615 T5947 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 1502632 T5947 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard3
   [junit4]   2> 1502639 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1502639 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1502639 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1502646 T5947 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1502647 T5947 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C1162 name=collection1 org.apache.solr.core.SolrCore@5947a1 url=https://127.0.0.1:49209/collection1 node=127.0.0.1:49209_ C1162_STATE=coll:collection1 core:collection1 props:{state=down, base_url=https://127.0.0.1:49209, core=collection1, node_name=127.0.0.1:49209_}
   [junit4]   2> 1502647 T5947 C1162 P49209 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:49209/collection1/
   [junit4]   2> 1502647 T5947 C1162 P49209 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1502647 T5947 C1162 P49209 oasc.SyncStrategy.syncToMe https://127.0.0.1:49209/collection1/ has no replicas
   [junit4]   2> 1502647 T5947 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:49209/collection1/ shard3
   [junit4]   2> 1502647 T5947 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
   [junit4]   2> 1502653 T5903 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1502668 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1502672 T5902 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> 1502672 T5942 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> 1502673 T5911 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> 1502674 T5924 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> 1502690 T5903 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1502698 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1502799 T5924 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> 1502800 T5902 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> 1502800 T5942 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> 1502802 T5911 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> 1502826 T5947 oasc.ZkController.register We are https://127.0.0.1:49209/collection1/ and leader is https://127.0.0.1:49209/collection1/
   [junit4]   2> 1502826 T5947 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:49209
   [junit4]   2> 1502826 T5947 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1502826 T5947 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1502827 T5947 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1502830 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1502830 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1502830 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1502834 T5947 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1502837 T5903 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1502839 T5903 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:49209",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49209_",
   [junit4]   2> 	  "shard":"shard3",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 1502846 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1502947 T5924 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> 1502948 T5902 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> 1502948 T5942 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> 1502949 T5911 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> 1503154 T5878 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
   [junit4]   2> 1503155 T5878 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1503165 T5878 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 1503167 T5878 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:49218
   [junit4]   2> 1503172 T5878 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1503172 T5878 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1503172 T5878 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392936948181
   [junit4]   2> 1503173 T5878 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392936948181\'
   [junit4]   2> 1503208 T5878 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392936948181\solr.xml
   [junit4]   2> 1503264 T5878 oasc.CoreContainer.<init> New CoreContainer 22467617
   [junit4]   2> 1503265 T5878 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392936948181\]
   [junit4]   2> 1503266 T5878 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1503266 T5878 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1503266 T5878 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1503266 T5878 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1503266 T5878 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1503267 T5878 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1503267 T5878 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1503267 T5878 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1503268 T5878 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1503276 T5878 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1503276 T5878 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1503279 T5878 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1503279 T5878 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49178/solr
   [junit4]   2> 1503279 T5878 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1503281 T5878 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1503286 T5958 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3865ae name:ZooKeeperConnection Watcher:127.0.0.1:49178 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1503287 T5878 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1503290 T5880 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1445182ea03000a, likely client has closed socket
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
   [junit4]   2> 	at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
   [junit4]   2> 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 
   [junit4]   2> 1503292 T5878 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1503295 T5960 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1226306 name:ZooKeeperConnection Watcher:127.0.0.1:49178/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1503295 T5878 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1503303 T5878 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1504241 T5878 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49218_
   [junit4]   2> 1504244 T5878 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49218_
   [junit4]   2> 1504249 T5902 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1504249 T5911 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1504249 T5942 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1504249 T5924 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1504249 T5960 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1504265 T5961 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1504265 T5961 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1504267 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1504267 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1504268 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1504267 T5961 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1504269 T5903 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1504269 T5903 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:49218",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:49218_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1504269 T5903 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 1504269 T5903 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1504273 T5902 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1504370 T5960 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> 1504370 T5902 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> 1504370 T5942 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> 1504370 T5924 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> 1504371 T5911 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> 1505200 T5961 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1505200 T5961 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392936948181\collection1
   [junit4]   2> 1505201 T5961 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1505202 T5961 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1505202 T5961 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1505204 T5961 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1505204 T5961 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392936948181\collection1\'
   [junit4]   2> 1505206 T5961 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392936948181/collection1/lib/classes/' to classloader
   [junit4]   2> 1505209 T5961 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392936948181/collection1/lib/README' to classloader
   [junit4]   2> 1505275 T5961 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
   [junit4]   2> 1505322 T5961 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1505324 T5961 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1505333 T5961 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1505714 T5961 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1505717 T5961 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1505718 T5961 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1505723 T5961 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1505755 T5961 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 1505756 T5961 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392936948181\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968/jetty3\
   [junit4]   2> 1505756 T5961 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@f000b2
   [junit4]   2> 1505756 T5961 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968\jetty3
   [junit4]   2> 1505758 T5961 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968/jetty3\index/
   [junit4]   2> 1505758 T5961 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968\jetty3\index' doesn't exist. Creating new index...
   [junit4]   2> 1505760 T5961 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968\jetty3\index
   [junit4]   2> 1505761 T5961 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=6, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8530789027716157]
   [junit4]   2> 1505767 T5961 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392936937968\jetty3\index,segFN=segments_1,generation=1}
   [junit4]   2> 1505767 T5961 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1505771 T5961 oasup.UpdateRequestProce

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

he.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:254)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:254)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 1633170 T5978 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 1633177 T5978 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 1633174 T6117 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 1633178 T6117 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:254)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:254)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> 1633178 T5978 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
   [junit4]   2> 	at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
   [junit4]   2> 	at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:257)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:254)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:254)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:92)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:137)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
   [junit4]   2> 	at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
   [junit4]   2> 
   [junit4]   2> NOTE: test params are: codec=Lucene46: {rnd_b=MockVariableIntBlock(baseBlockSize=60), _version_=Lucene41(blocksize=128), a_t=FST41, a_si=Lucene41(blocksize=128), id=MockVariableIntBlock(baseBlockSize=60)}, docValues:{}, sim=DefaultSimilarity, locale=ru, timezone=Arctic/Longyearbyen
   [junit4]   2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.7.0_60-ea (32-bit)/cpus=2,threads=1,free=249291672,total=445120512
   [junit4]   2> NOTE: All tests run in this JVM: [TestCoreDiscovery, HighlighterConfigTest, TestArbitraryIndexDir, SuggesterFSTTest, TestSolrIndexConfig, CoreAdminHandlerTest, SimpleFacetsTest, ShardRoutingCustomTest, TestAnalyzeInfixSuggestions, OpenCloseCoreStressTest, TestSort, TestDynamicFieldCollectionResource, TestDefaultSimilarityFactory, TestSystemIdResolver, TestQuerySenderNoQuery, TestWordDelimiterFilterFactory, SliceStateUpdateTest, AddBlockUpdateTest, TestPhraseSuggestions, TestSerializedLuceneMatchVersion, TestLazyCores, UpdateParamsTest, DistributedSpellCheckComponentTest, ExternalFileFieldSortTest, TestSolrCoreProperties, IndexBasedSpellCheckerTest, MigrateRouteKeyTest, TestDistribDocBasedVersion, TestOmitPositions, TestManagedSchemaFieldResource, WordBreakSolrSpellCheckerTest, SyncSliceTest, LoggingHandlerTest, TestOverriddenPrefixQueryForCustomFieldType, TestBlendedInfixSuggestions, TestJmxIntegration, ZkControllerTest, PingRequestHandlerTest, TestSurroundQueryParser, TestCharFilters, CSVRequestHandlerTest, TestPartialUpdateDeduplication, TestInfoStreamLogging, TestStressVersions, TestRealTimeGet, TestExtendedDismaxParser, TestCSVResponseWriter, QueryResultKeyTest, HdfsSyncSliceTest, TestSchemaVersionResource, TestDFRSimilarityFactory, SolrCoreTest, SystemInfoHandlerTest, TestNonNRTOpen, CachingDirectoryFactoryTest, TestFuzzyAnalyzedSuggestions, QueryParsingTest, SolrTestCaseJ4Test, TestStressLucene, TestCloudManagedSchemaAddField, RegexBoostProcessorTest, TestMultiCoreConfBootstrap, EnumFieldTest, TestCSVLoader, TestRTGBase, SuggesterTest, TestIndexingPerformance, TriLevelCompositeIdRoutingTest, CurrencyFieldOpenExchangeTest, CircularListTest, DateFieldTest, DisMaxRequestHandlerTest, TestElisionMultitermQuery, SimplePostToolTest, XmlUpdateRequestHandlerTest, TestHighlightDedupGrouping, TestInitQParser, TestFieldTypeCollectionResource, TestFunctionQuery, RequestHandlersTest, TestCopyFieldCollectionResource, BJQParserTest, BadComponentTest, TestRandomDVFaceting, TestSolrJ, IndexSchemaTest, TestCloudManagedSchema, TestDynamicFieldResource, TestReload, SolrPluginUtilsTest, TestHashPartitioner, NotRequiredUniqueKeyTest, BasicDistributedZk2Test, TestCollationFieldDocValues, BadIndexSchemaTest, TestUpdate, BasicZkTest, TermVectorComponentTest, CopyFieldTest, HighlighterTest, TestRangeQuery, HdfsRecoveryZkTest, TestFastLRUCache, SpatialFilterTest, ClusterStateUpdateTest, BasicDistributedZkTest, ChangedSchemaMergeTest, TestAnalyzedSuggestions, HdfsBasicDistributedZkTest, SoftAutoCommitTest, DeleteShardTest, DocumentAnalysisRequestHandlerTest, DateMathParserTest, SuggesterTSTTest, TestNumberUtils, MBeansHandlerTest, TestDistributedSearch, TestFieldResource, SortByFunctionTest, CurrencyFieldXmlFileTest, OverseerTest, TestIBSimilarityFactory, CollectionsAPIDistributedZkTest, FieldMutatingUpdateProcessorTest, LeaderElectionTest, CoreContainerCoreInitFailuresTest, XsltUpdateRequestHandlerTest, SOLR749Test, TestSuggestSpellingConverter, BadCopyFieldTest, TestIndexSearcher, TestLuceneMatchVersion, ClusterStateTest, TestReversedWildcardFilterFactory, AddSchemaFieldsUpdateProcessorFactoryTest, DebugComponentTest, TestPostingsSolrHighlighter, TestCollapseQParserPlugin, DirectUpdateHandlerOptimizeTest, JsonLoaderTest, BinaryUpdateRequestHandlerTest, FullSolrCloudDistribCmdsTest, AliasIntegrationTest, DirectSolrConnectionTest, FileUtilsTest, TestRecoveryHdfs, UpdateRequestProcessorFactoryTest, TestPHPSerializedResponseWriter, TestSolrXmlPersistence, MoreLikeThisHandlerTest, TestSolrQueryParser, TestDocumentBuilder, TestLMJelinekMercerSimilarityFactory, TestSolr4Spatial, TestSweetSpotSimilarityFactory, TestQueryUtils, OverseerCollectionProcessorTest, TestCodecSupport, TestValueSourceCache, NoCacheHeaderTest, TestSolrXml, TestSolrXmlPersistor, TestXIncludeConfig, TestStressRecovery, TestSolrXMLSerializer, FastVectorHighlighterTest, SolrRequestParserTest, SampleTest, CursorPagingTest, TestNoOpRegenerator, PrimUtilsTest, TestTrie, StandardRequestHandlerTest, TestJmxMonitoredMap, ChaosMonkeySafeLeaderTest]
   [junit4] Completed in 141.80s, 1 test, 1 error <<< FAILURES!

[...truncated 558 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:459: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:439: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\extra-targets.xml:37: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build.xml:189: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\common-build.xml:491: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1272: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:905: There were test failures: 362 suites, 1563 tests, 1 error, 40 ignored (12 assumptions)

Total time: 81 minutes 43 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_60-ea-b04 -client -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure