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/19 20:33:48 UTC

[JENKINS] Lucene-Solr-4.x-Windows (32bit/jdk1.8.0-fcs-b129) - Build # 3721 - Still Failing!

Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/3721/
Java: 32bit/jdk1.8.0-fcs-b129 -server -XX:+UseParallelGC

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

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

Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=5812, name=RecoveryThread, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
	at __randomizedtesting.SeedInfo.seed([9894C814A16367CD:1972460CD63C07F1]:0)
Caused by: java.lang.AssertionError: file _1.cfe does not exist
	at __randomizedtesting.SeedInfo.seed([9894C814A16367CD]: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 10558 lines...]
   [junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
   [junit4]   2> 1583160 T5462 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
   [junit4]   2> 1583160 T5462 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
   [junit4]   2> 1583163 T5462 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-1392837053177
   [junit4]   2> 1583166 T5462 oasc.ZkTestServer.run STARTING ZK TEST SERVER
   [junit4]   2> 1583167 T5463 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
   [junit4]   2> 1583267 T5462 oasc.ZkTestServer.run start zk server on port:52687
   [junit4]   2> 1583270 T5462 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1583276 T5469 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e519b name:ZooKeeperConnection Watcher:127.0.0.1:52687 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1583277 T5462 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1583277 T5462 oascc.SolrZkClient.makePath makePath: /solr
   [junit4]   2> 1583283 T5464 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1444b8ecb030000, 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> 1583286 T5462 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1583289 T5471 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10b09da name:ZooKeeperConnection Watcher:127.0.0.1:52687/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1583289 T5462 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1583289 T5462 oascc.SolrZkClient.makePath makePath: /collections/collection1
   [junit4]   2> 1583293 T5462 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
   [junit4]   2> 1583296 T5462 oascc.SolrZkClient.makePath makePath: /collections/control_collection
   [junit4]   2> 1583299 T5462 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
   [junit4]   2> 1583303 T5462 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> 1583303 T5462 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
   [junit4]   2> 1583309 T5462 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> 1583309 T5462 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
   [junit4]   2> 1583315 T5462 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> 1583315 T5462 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.snippet.randomindexconfig.xml
   [junit4]   2> 1583319 T5462 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> 1583319 T5462 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
   [junit4]   2> 1583323 T5462 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> 1583323 T5462 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
   [junit4]   2> 1583328 T5462 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> 1583328 T5462 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
   [junit4]   2> 1583333 T5462 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> 1583333 T5462 oascc.SolrZkClient.makePath makePath: /configs/conf1/enumsConfig.xml
   [junit4]   2> 1583336 T5462 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> 1583336 T5462 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
   [junit4]   2> 1583341 T5462 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> 1583341 T5462 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
   [junit4]   2> 1583346 T5462 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> 1583346 T5462 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
   [junit4]   2> 1583350 T5462 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> 1583350 T5462 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
   [junit4]   2> 1583357 T5464 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1444b8ecb030001, 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> 1583359 T5462 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1583362 T5473 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@62fba8 name:ZooKeeperConnection Watcher:127.0.0.1:52687/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1583362 T5462 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1583917 T5462 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1583928 T5462 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 1583933 T5462 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:52697
   [junit4]   2> 1583937 T5462 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1583937 T5462 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1583938 T5462 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392837053376
   [junit4]   2> 1583938 T5462 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392837053376\'
   [junit4]   2> 1583969 T5462 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-1392837053376\solr.xml
   [junit4]   2> 1583980 T5462 oasc.CoreContainer.<init> New CoreContainer 27196193
   [junit4]   2> 1583980 T5462 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392837053376\]
   [junit4]   2> 1583981 T5462 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1583981 T5462 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1583982 T5462 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1583982 T5462 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1583982 T5462 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1583983 T5462 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1583983 T5462 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1583983 T5462 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1583984 T5462 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1583994 T5462 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1583994 T5462 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1583994 T5462 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1583995 T5462 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52687/solr
   [junit4]   2> 1583995 T5462 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1583997 T5462 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1584005 T5484 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f60450 name:ZooKeeperConnection Watcher:127.0.0.1:52687 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1584006 T5462 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1584015 T5462 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1584018 T5486 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@58993f name:ZooKeeperConnection Watcher:127.0.0.1:52687/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1584019 T5462 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1584022 T5462 oascc.SolrZkClient.makePath makePath: /overseer/queue
   [junit4]   2> 1584028 T5462 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
   [junit4]   2> 1584034 T5462 oascc.SolrZkClient.makePath makePath: /live_nodes
   [junit4]   2> 1584038 T5462 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52697_
   [junit4]   2> 1584039 T5462 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52697_
   [junit4]   2> 1584044 T5462 oascc.SolrZkClient.makePath makePath: /overseer_elect
   [junit4]   2> 1584047 T5462 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
   [junit4]   2> 1584055 T5462 oasc.OverseerElectionContext.runLeaderProcess I am going to be the leader 127.0.0.1:52697_
   [junit4]   2> 1584055 T5462 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
   [junit4]   2> 1584058 T5462 oasc.Overseer.start Overseer (id=91280969117663236-127.0.0.1:52697_-n_0000000000) starting
   [junit4]   2> 1584064 T5462 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
   [junit4]   2> 1584071 T5488 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
   [junit4]   2> 1584072 T5462 oascc.SolrZkClient.makePath makePath: /clusterstate.json
   [junit4]   2> 1584072 T5488 oasc.OverseerCollectionProcessor.prioritizeOverseerNodes prioritizing overseer nodes
   [junit4]   2> 1584076 T5462 oascc.SolrZkClient.makePath makePath: /aliases.json
   [junit4]   2> 1584079 T5462 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1584083 T5487 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
   [junit4]   2> 1584089 T5489 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1584090 T5489 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1584091 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1584092 T5489 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1584094 T5487 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1584095 T5487 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:52697",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52697_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"1",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1584095 T5487 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with shards [shard1]
   [junit4]   2> 1584095 T5487 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1584100 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1584101 T5486 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> 1585092 T5489 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1585092 T5489 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392837053376\collection1
   [junit4]   2> 1585092 T5489 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
   [junit4]   2> 1585093 T5489 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1585093 T5489 oascc.ZkStateReader.readConfigName Load collection config from:/collections/control_collection
   [junit4]   2> 1585095 T5489 oascc.ZkStateReader.readConfigName path=/collections/control_collection configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1585095 T5489 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392837053376\collection1\'
   [junit4]   2> 1585095 T5489 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-1392837053376/collection1/lib/classes/' to classloader
   [junit4]   2> 1585097 T5489 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-1392837053376/collection1/lib/README' to classloader
   [junit4]   2> 1585126 T5489 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
   [junit4]   2> 1585133 T5489 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1585138 T5489 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1585141 T5489 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1585250 T5489 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1585252 T5489 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1585253 T5489 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1585256 T5489 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1585286 T5489 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 1585286 T5489 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1392837053376\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392837053175/control/data\
   [junit4]   2> 1585286 T5489 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@40aba5
   [junit4]   2> 1585286 T5489 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-1392837053175\control\data
   [junit4]   2> 1585288 T5489 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392837053175/control/data\index/
   [junit4]   2> 1585288 T5489 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392837053175\control\data\index' doesn't exist. Creating new index...
   [junit4]   2> 1585288 T5489 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-1392837053175\control\data\index
   [junit4]   2> 1585290 T5489 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=44, maxMergedSegmentMB=32.7314453125, floorSegmentMB=0.52734375, forceMergeDeletesPctAllowed=15.149862520016269, segmentsPerTier=23.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 1585295 T5489 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-1392837053175\control\data\index,segFN=segments_1,generation=1}
   [junit4]   2> 1585295 T5489 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1585298 T5489 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1585298 T5489 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1585299 T5489 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1585299 T5489 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1585299 T5489 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1585299 T5489 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1585300 T5489 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1585300 T5489 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1585300 T5489 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1585300 T5489 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1585301 T5489 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1585301 T5489 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1585301 T5489 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1585301 T5489 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1585302 T5489 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1585302 T5489 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1585306 T5489 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1585310 T5489 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1585310 T5489 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1585311 T5489 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=33, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 1585311 T5489 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-1392837053175\control\data\index,segFN=segments_1,generation=1}
   [junit4]   2> 1585311 T5489 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1585311 T5489 oass.SolrIndexSearcher.<init> Opening Searcher@7624e8[collection1] main
   [junit4]   2> 1585315 T5490 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7624e8[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1585316 T5489 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1585317 T5462 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 1585318 T5462 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1585317 T5493 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:52697 collection:control_collection shard:shard1
   [junit4]   2> 1585320 T5493 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
   [junit4]   2> 1585328 T5462 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1585332 T5495 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ebed71 name:ZooKeeperConnection Watcher:127.0.0.1:52687/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1585332 T5462 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1585332 T5493 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard1
   [junit4]   2> 1585334 T5462 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1585336 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1585336 T5493 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1585336 T5493 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C879 name=collection1 org.apache.solr.core.SolrCore@39f596 url=https://127.0.0.1:52697/collection1 node=127.0.0.1:52697_ C879_STATE=coll:control_collection core:collection1 props:{state=down, base_url=https://127.0.0.1:52697, core=collection1, node_name=127.0.0.1:52697_}
   [junit4]   2> 1585336 T5493 C879 P52697 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:52697/collection1/
   [junit4]   2> 1585337 T5493 C879 P52697 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1585337 T5493 C879 P52697 oasc.SyncStrategy.syncToMe https://127.0.0.1:52697/collection1/ has no replicas
   [junit4]   2> 1585337 T5493 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:52697/collection1/ shard1
   [junit4]   2> 1585337 T5493 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
   [junit4]   2> 1585338 T5487 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1585338 T5462 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:false cause connection loss:false
   [junit4]   2> 1585347 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1585353 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1585360 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1585465 T5495 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> 1585465 T5486 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> 1585507 T5493 oasc.ZkController.register We are https://127.0.0.1:52697/collection1/ and leader is https://127.0.0.1:52697/collection1/
   [junit4]   2> 1585507 T5493 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:52697
   [junit4]   2> 1585507 T5493 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1585507 T5493 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1585507 T5493 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1585510 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1585510 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1585510 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1585512 T5493 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1585514 T5487 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1585514 T5487 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:52697",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52697_",
   [junit4]   2> 	  "shard":"shard1",
   [junit4]   2> 	  "collection":"control_collection",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 1585528 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1585632 T5495 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> 1585632 T5486 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> 1585893 T5462 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 1
   [junit4]   2> 1585894 T5462 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1585905 T5462 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 1585907 T5462 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:52709
   [junit4]   2> 1585910 T5462 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1585910 T5462 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1585910 T5462 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392837055351
   [junit4]   2> 1585910 T5462 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392837055351\'
   [junit4]   2> 1585939 T5462 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-1392837055351\solr.xml
   [junit4]   2> 1585952 T5462 oasc.CoreContainer.<init> New CoreContainer 14030991
   [junit4]   2> 1585952 T5462 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392837055351\]
   [junit4]   2> 1585953 T5462 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1585953 T5462 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1585954 T5462 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1585954 T5462 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1585954 T5462 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1585955 T5462 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1585955 T5462 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1585955 T5462 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1585956 T5462 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1585965 T5462 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1585965 T5462 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1585966 T5462 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1585966 T5462 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52687/solr
   [junit4]   2> 1585967 T5462 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1585969 T5462 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1585974 T5506 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@153d34e name:ZooKeeperConnection Watcher:127.0.0.1:52687 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1585975 T5462 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1585978 T5464 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1444b8ecb030006, 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> 1585979 T5462 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1585982 T5508 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@599874 name:ZooKeeperConnection Watcher:127.0.0.1:52687/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1585982 T5462 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1585989 T5462 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1586993 T5462 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52709_
   [junit4]   2> 1586995 T5462 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52709_
   [junit4]   2> 1586999 T5508 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1587000 T5486 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1587000 T5495 oascc.ZkStateReader$3.process Updating live nodes... (2)
   [junit4]   2> 1587009 T5509 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1587009 T5509 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1587012 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1587012 T5509 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1587013 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1587013 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1587016 T5487 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1587016 T5487 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:52709",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52709_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1587016 T5487 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with shards [shard1, shard2, shard3]
   [junit4]   2> 1587016 T5487 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
   [junit4]   2> 1587021 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1587125 T5508 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> 1587125 T5495 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> 1587126 T5486 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> 1588013 T5509 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1588013 T5509 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392837055351\collection1
   [junit4]   2> 1588014 T5509 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1588015 T5509 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1588015 T5509 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1588017 T5509 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1588017 T5509 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392837055351\collection1\'
   [junit4]   2> 1588017 T5509 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-1392837055351/collection1/lib/classes/' to classloader
   [junit4]   2> 1588017 T5509 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-1392837055351/collection1/lib/README' to classloader
   [junit4]   2> 1588047 T5509 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
   [junit4]   2> 1588052 T5509 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1588057 T5509 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1588060 T5509 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1588174 T5509 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1588176 T5509 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1588177 T5509 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1588181 T5509 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1588219 T5509 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 1588220 T5509 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1392837055351\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392837053175/jetty1\
   [junit4]   2> 1588220 T5509 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@40aba5
   [junit4]   2> 1588222 T5509 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-1392837053175\jetty1
   [junit4]   2> 1588222 T5509 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392837053175/jetty1\index/
   [junit4]   2> 1588225 T5509 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392837053175\jetty1\index' doesn't exist. Creating new index...
   [junit4]   2> 1588225 T5509 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-1392837053175\jetty1\index
   [junit4]   2> 1588227 T5509 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=44, maxMergedSegmentMB=32.7314453125, floorSegmentMB=0.52734375, forceMergeDeletesPctAllowed=15.149862520016269, segmentsPerTier=23.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 1588233 T5509 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-1392837053175\jetty1\index,segFN=segments_1,generation=1}
   [junit4]   2> 1588233 T5509 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1588236 T5509 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1588236 T5509 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1588236 T5509 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1588237 T5509 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1588237 T5509 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1588237 T5509 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1588237 T5509 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1588238 T5509 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1588238 T5509 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1588238 T5509 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1588239 T5509 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1588239 T5509 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1588239 T5509 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1588240 T5509 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1588240 T5509 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1588240 T5509 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1588245 T5509 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1588248 T5509 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1588249 T5509 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1588250 T5509 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=33, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 1588251 T5509 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-1392837053175\jetty1\index,segFN=segments_1,generation=1}
   [junit4]   2> 1588251 T5509 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1588251 T5509 oass.SolrIndexSearcher.<init> Opening Searcher@1952e8b[collection1] main
   [junit4]   2> 1588254 T5509 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1588254 T5510 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1952e8b[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1588256 T5462 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 1588256 T5462 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1588275 T5513 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:52709 collection:collection1 shard:shard2
   [junit4]   2> 1588311 T5513 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
   [junit4]   2> 1588322 T5513 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard2
   [junit4]   2> 1588326 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1588326 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1588326 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1588327 T5513 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1588327 T5513 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C880 name=collection1 org.apache.solr.core.SolrCore@18bbeca url=https://127.0.0.1:52709/collection1 node=127.0.0.1:52709_ C880_STATE=coll:collection1 core:collection1 props:{state=down, base_url=https://127.0.0.1:52709, core=collection1, node_name=127.0.0.1:52709_}
   [junit4]   2> 1588327 T5513 C880 P52709 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:52709/collection1/
   [junit4]   2> 1588327 T5513 C880 P52709 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1588327 T5513 C880 P52709 oasc.SyncStrategy.syncToMe https://127.0.0.1:52709/collection1/ has no replicas
   [junit4]   2> 1588329 T5513 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:52709/collection1/ shard2
   [junit4]   2> 1588329 T5513 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
   [junit4]   2> 1588331 T5487 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1588338 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1588342 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1588350 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1588457 T5508 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> 1588458 T5495 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> 1588459 T5486 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> 1588496 T5513 oasc.ZkController.register We are https://127.0.0.1:52709/collection1/ and leader is https://127.0.0.1:52709/collection1/
   [junit4]   2> 1588496 T5513 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:52709
   [junit4]   2> 1588496 T5513 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1588496 T5513 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1588496 T5513 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1588499 T5513 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1588499 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1588500 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1588500 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1588503 T5487 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1588503 T5487 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:52709",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52709_",
   [junit4]   2> 	  "shard":"shard2",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node1"}
   [junit4]   2> 1588508 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1588612 T5508 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> 1588612 T5495 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> 1588613 T5486 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> 1588788 T5462 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 2
   [junit4]   2> 1588789 T5462 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1588807 T5462 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 1588810 T5462 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:52718
   [junit4]   2> 1588816 T5462 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1588816 T5462 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1588817 T5462 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: .\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392837058271
   [junit4]   2> 1588817 T5462 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392837058271\'
   [junit4]   2> 1588843 T5462 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-1392837058271\solr.xml
   [junit4]   2> 1588854 T5462 oasc.CoreContainer.<init> New CoreContainer 2234667
   [junit4]   2> 1588856 T5462 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392837058271\]
   [junit4]   2> 1588856 T5462 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1588857 T5462 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1588857 T5462 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1588857 T5462 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1588857 T5462 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1588858 T5462 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1588858 T5462 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1588859 T5462 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1588859 T5462 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1588868 T5462 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1588869 T5462 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1588869 T5462 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1588870 T5462 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52687/solr
   [junit4]   2> 1588870 T5462 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1588873 T5462 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1588878 T5524 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9b005e name:ZooKeeperConnection Watcher:127.0.0.1:52687 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1588878 T5462 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1588880 T5464 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1444b8ecb030008, 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> 1588882 T5462 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1588885 T5526 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f4961a name:ZooKeeperConnection Watcher:127.0.0.1:52687/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1588886 T5462 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1588892 T5462 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1589896 T5462 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52718_
   [junit4]   2> 1589899 T5462 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52718_
   [junit4]   2> 1589904 T5508 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1589904 T5495 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1589905 T5526 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1589905 T5486 oascc.ZkStateReader$3.process Updating live nodes... (3)
   [junit4]   2> 1589917 T5527 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1589917 T5527 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1589919 T5527 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1589919 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1589920 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1589920 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1589921 T5487 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1589922 T5487 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:52718",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52718_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1589922 T5487 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 1589922 T5487 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
   [junit4]   2> 1589927 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1590031 T5508 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> 1590032 T5486 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> 1590032 T5526 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> 1590032 T5495 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> 1590919 T5527 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1590919 T5527 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: .\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392837058271\collection1
   [junit4]   2> 1590919 T5527 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1590920 T5527 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1590920 T5527 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1590922 T5527 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1590922 T5527 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392837058271\collection1\'
   [junit4]   2> 1590925 T5527 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-1392837058271/collection1/lib/classes/' to classloader
   [junit4]   2> 1590925 T5527 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-1392837058271/collection1/lib/README' to classloader
   [junit4]   2> 1590955 T5527 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
   [junit4]   2> 1590961 T5527 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1590964 T5527 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1590969 T5527 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1591074 T5527 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1591074 T5527 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1591074 T5527 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1591080 T5527 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1591108 T5527 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 1591109 T5527 oasc.SolrCore.<init> [collection1] Opening new SolrCore at .\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1392837058271\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392837053175/jetty2\
   [junit4]   2> 1591109 T5527 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@40aba5
   [junit4]   2> 1591109 T5527 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-1392837053175\jetty2
   [junit4]   2> 1591109 T5527 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392837053175/jetty2\index/
   [junit4]   2> 1591111 T5527 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392837053175\jetty2\index' doesn't exist. Creating new index...
   [junit4]   2> 1591111 T5527 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-1392837053175\jetty2\index
   [junit4]   2> 1591112 T5527 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=44, maxMergedSegmentMB=32.7314453125, floorSegmentMB=0.52734375, forceMergeDeletesPctAllowed=15.149862520016269, segmentsPerTier=23.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 1591118 T5527 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-1392837053175\jetty2\index,segFN=segments_1,generation=1}
   [junit4]   2> 1591118 T5527 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1591121 T5527 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1591121 T5527 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 1591122 T5527 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
   [junit4]   2> 1591122 T5527 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1591122 T5527 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
   [junit4]   2> 1591122 T5527 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
   [junit4]   2> 1591123 T5527 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1591123 T5527 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
   [junit4]   2> 1591123 T5527 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 1591124 T5527 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
   [junit4]   2> 1591124 T5527 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 1591124 T5527 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
   [junit4]   2> 1591124 T5527 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 1591125 T5527 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 1591125 T5527 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
   [junit4]   2> 1591125 T5527 oasc.RequestHandlers.initHandlersFromConfig created /admin/file: solr.admin.ShowFileRequestHandler
   [junit4]   2> 1591130 T5527 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 1591132 T5527 oasu.CommitTracker.<init> Hard AutoCommit: disabled
   [junit4]   2> 1591132 T5527 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 1591133 T5527 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=33, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
   [junit4]   2> 1591134 T5527 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-1392837053175\jetty2\index,segFN=segments_1,generation=1}
   [junit4]   2> 1591134 T5527 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1591134 T5527 oass.SolrIndexSearcher.<init> Opening Searcher@b34216[collection1] main
   [junit4]   2> 1591138 T5528 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@b34216[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 1591139 T5527 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 1591140 T5462 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
   [junit4]   2> 1591141 T5462 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 1591141 T5531 oasc.ZkController.register Register replica - core:collection1 address:https://127.0.0.1:52718 collection:collection1 shard:shard3
   [junit4]   2> 1591143 T5531 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
   [junit4]   2> 1591153 T5531 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process for shard shard3
   [junit4]   2> 1591157 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1591157 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1591157 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1591164 T5487 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1591166 T5531 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
   [junit4]   2> 1591167 T5531 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
   [junit4]   2> ASYNC  NEW_CORE C881 name=collection1 org.apache.solr.core.SolrCore@d6d220 url=https://127.0.0.1:52718/collection1 node=127.0.0.1:52718_ C881_STATE=coll:collection1 core:collection1 props:{state=down, base_url=https://127.0.0.1:52718, core=collection1, node_name=127.0.0.1:52718_}
   [junit4]   2> 1591167 T5531 C881 P52718 oasc.SyncStrategy.sync Sync replicas to https://127.0.0.1:52718/collection1/
   [junit4]   2> 1591167 T5531 C881 P52718 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
   [junit4]   2> 1591167 T5531 C881 P52718 oasc.SyncStrategy.syncToMe https://127.0.0.1:52718/collection1/ has no replicas
   [junit4]   2> 1591168 T5531 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: https://127.0.0.1:52718/collection1/ shard3
   [junit4]   2> 1591168 T5531 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
   [junit4]   2> 1591171 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1591177 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1591182 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1591290 T5508 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> 1591290 T5526 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> 1591291 T5495 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> 1591291 T5486 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> 1591332 T5531 oasc.ZkController.register We are https://127.0.0.1:52718/collection1/ and leader is https://127.0.0.1:52718/collection1/
   [junit4]   2> 1591332 T5531 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=https://127.0.0.1:52718
   [junit4]   2> 1591332 T5531 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
   [junit4]   2> 1591332 T5531 oasc.ZkController.publish publishing core=collection1 state=active
   [junit4]   2> 1591332 T5531 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1591335 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1591335 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1591336 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1591336 T5531 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1591338 T5487 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1591339 T5487 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:52718",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52718_",
   [junit4]   2> 	  "shard":"shard3",
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":"core_node2"}
   [junit4]   2> 1591344 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1591448 T5526 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> 1591448 T5508 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> 1591449 T5486 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> 1591449 T5495 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> 1591661 T5462 oasc.AbstractFullDistribZkTestBase.createJettys create jetty 3
   [junit4]   2> 1591662 T5462 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 1591671 T5462 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 1591675 T5462 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:52727
   [junit4]   2> 1591678 T5462 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 1591678 T5462 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 1591678 T5462 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392837061158
   [junit4]   2> 1591678 T5462 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392837061158\'
   [junit4]   2> 1591720 T5462 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392837061158\solr.xml
   [junit4]   2> 1591733 T5462 oasc.CoreContainer.<init> New CoreContainer 10624274
   [junit4]   2> 1591733 T5462 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392837061158\]
   [junit4]   2> 1591735 T5462 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 90000
   [junit4]   2> 1591735 T5462 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: 
   [junit4]   2> 1591735 T5462 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
   [junit4]   2> 1591735 T5462 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 1591735 T5462 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 1591735 T5462 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 1591737 T5462 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 1591737 T5462 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 1591737 T5462 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 1591747 T5462 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 1591747 T5462 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 1591747 T5462 oasc.CoreContainer.load Host Name: 127.0.0.1
   [junit4]   2> 1591750 T5462 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52687/solr
   [junit4]   2> 1591750 T5462 oasc.ZkController.checkChrootPath zkHost includes chroot
   [junit4]   2> 1591752 T5462 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1591759 T5542 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1dc6e87 name:ZooKeeperConnection Watcher:127.0.0.1:52687 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1591760 T5462 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1591763 T5464 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x1444b8ecb03000a, 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> 1591764 T5462 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
   [junit4]   2> 1591767 T5544 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7463f7 name:ZooKeeperConnection Watcher:127.0.0.1:52687/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
   [junit4]   2> 1591767 T5462 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
   [junit4]   2> 1591776 T5462 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
   [junit4]   2> 1592781 T5462 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52727_
   [junit4]   2> 1592783 T5462 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52727_
   [junit4]   2> 1592788 T5526 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1592788 T5544 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1592788 T5508 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1592788 T5486 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1592789 T5495 oascc.ZkStateReader$3.process Updating live nodes... (4)
   [junit4]   2> 1592796 T5545 oasc.ZkController.publish publishing core=collection1 state=down
   [junit4]   2> 1592796 T5545 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
   [junit4]   2> 1592798 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1592798 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1592798 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1592798 T5545 oasc.ZkController.waitForCoreNodeName look for our core node name
   [junit4]   2> 1592801 T5487 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
   [junit4]   2> 1592801 T5487 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:52727",
   [junit4]   2> 	  "core":"collection1",
   [junit4]   2> 	  "roles":null,
   [junit4]   2> 	  "node_name":"127.0.0.1:52727_",
   [junit4]   2> 	  "shard":null,
   [junit4]   2> 	  "collection":"collection1",
   [junit4]   2> 	  "numShards":"3",
   [junit4]   2> 	  "core_node_name":null}
   [junit4]   2> 1592801 T5487 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
   [junit4]   2> 1592801 T5487 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
   [junit4]   2> 1592805 T5486 oasc.DistributedQueue$LatchChildWatcher.process LatchChildWatcher fired on path: /overseer/queue state: SyncConnected type NodeChildrenChanged
   [junit4]   2> 1592910 T5544 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> 1592910 T5526 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> 1592910 T5508 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> 1592911 T5495 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> 1592911 T5486 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> 1593798 T5545 oasc.ZkController.waitForShardId waiting to find shard id in clusterstate for collection1
   [junit4]   2> 1593799 T5545 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392837061158\collection1
   [junit4]   2> 1593799 T5545 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
   [junit4]   2> 1593801 T5545 oasc.ZkController.createCollectionZkNode Collection zkNode exists
   [junit4]   2> 1593801 T5545 oascc.ZkStateReader.readConfigName Load collection config from:/collections/collection1
   [junit4]   2> 1593803 T5545 oascc.ZkStateReader.readConfigName path=/collections/collection1 configName=conf1 specified config exists in ZooKeeper
   [junit4]   2> 1593803 T5545 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392837061158\collection1\'
   [junit4]   2> 1593803 T5545 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-1392837061158/collection1/lib/classes/' to classloader
   [junit4]   2> 1593816 T5545 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-1392837061158/collection1/lib/README' to classloader
   [junit4]   2> 1593846 T5545 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
   [junit4]   2> 1593852 T5545 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 1593856 T5545 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 1593860 T5545 oass.IndexSchema.readSchema [collection1] Schema name=test
   [junit4]   2> 1593956 T5545 oass.IndexSchema.readSchema default search field in schema is text
   [junit4]   2> 1593959 T5545 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 1593959 T5545 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1593963 T5545 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 1593995 T5545 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
   [junit4]   2> 1593996 T5545 oasc.SolrCore.<init> [collection1] Opening new SolrCore at ..\..\..\..\..\..\..\..\..\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1392837061158\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392837053175/jetty3\
   [junit4]   2> 1593996 T5545 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@40aba5
   [junit4]   2> 1593996 T5545 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-1392837053175\jetty3
   [junit4]   2> 1593996 T5545 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392837053175/jetty3\index/
   [junit4]   2> 1593996 T5545 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1392837053175\jetty3\index' doesn't exist. Creating new index...
   [junit4]   2> 1593998 T5545 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-1392837053175\jetty3\index
   [junit4]   2> 1593999 T5545 oasu.RandomMergePolicy.<init> RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=44, maxMergedSegmentMB=32.7314453125, floorSegmentMB=0.52734375, forceMergeDeletesPctAllowed=15.149862520016269, segmentsPerTier=23.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 1594004 T5545 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-1392837053175\jetty3\index,segFN=segments_1,generation=1}
   [junit4]   2> 1594004 T5545 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 1594008 T5545 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "nodistrib"
   [junit4]   2> 1594008 T5545 oasup.UpdateRequestProcessorChain.init creating updateRequestProcessorChain "dedupe"
   [junit4]   2> 159400

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


   [junit4]   2> 		at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:273)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
   [junit4]   2> 		at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
   [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> 1687799 T5721 oasc.LeaderElector$1.process WARN  org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election/91280969117663261-core_node12-n_0000000003
   [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.delete(ZooKeeper.java:873)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:174)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:171)
   [junit4]   2> 	at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:73)
   [junit4]   2> 	at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:171)
   [junit4]   2> 	at org.apache.solr.cloud.ElectionContext.cancelElection(ElectionContext.java:67)
   [junit4]   2> 	at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:293)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:164)
   [junit4]   2> 	at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:108)
   [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> 1687802 T5721 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
   [junit4]   2> 1687802 T5721 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=FST41, _version_=Pulsing41(freqCutoff=4 minBlockSize=35 maxBlockSize=71), a_t=PostingsFormat(name=Asserting), a_si=Pulsing41(freqCutoff=4 minBlockSize=35 maxBlockSize=71), id=FST41}, docValues:{}, sim=DefaultSimilarity, locale=es_PA, timezone=Europe/Bucharest
   [junit4]   2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.8.0 (32-bit)/cpus=2,threads=1,free=117986576,total=298057728
   [junit4]   2> NOTE: All tests run in this JVM: [EnumFieldTest, StatelessScriptUpdateProcessorFactoryTest, TestCollapseQParserPlugin, TestFieldCollectionResource, QueryElevationComponentTest, TestFieldResource, TestPseudoReturnFields, HighlighterConfigTest, TestXIncludeConfig, TestHighFrequencyDictionaryFactory, TestNoOpRegenerator, ResponseLogComponentTest, DistributedSuggestComponentTest, TestPHPSerializedResponseWriter, TestAtomicUpdateErrorCases, TestDynamicFieldResource, ConnectionManagerTest, SampleTest, TestCoreContainer, DistributedQueryComponentCustomSortTest, TestSchemaVersionResource, TestLRUCache, CircularListTest, OverseerCollectionProcessorTest, SignatureUpdateProcessorFactoryTest, SuggestComponentTest, LeaderElectionTest, TestReloadAndDeleteDocs, SuggesterTest, HdfsChaosMonkeySafeLeaderTest, TestDistribDocBasedVersion, XmlUpdateRequestHandlerTest, TestFieldTypeCollectionResource, TestManagedSchema, BadCopyFieldTest, TestSolrXMLSerializer, TestGroupingSearch, TestFieldTypeResource, DirectUpdateHandlerOptimizeTest, TestSchemaResource, DateFieldTest, IndexBasedSpellCheckerTest, ZkNodePropsTest, FullSolrCloudDistribCmdsTest, QueryEqualityTest, NoCacheHeaderTest, PeerSyncTest, HardAutoCommitTest, TestAnalyzedSuggestions, ChaosMonkeyNothingIsSafeTest, TestCSVLoader, NumericFieldsTest, TestFastLRUCache, BJQParserTest, HdfsCollectionsAPIDistributedZkTest, TestWordDelimiterFilterFactory, TestRecoveryHdfs, TestSolrQueryParserDefaultOperatorResource, TestDocumentBuilder, RequiredFieldsTest, TestLuceneMatchVersion, TestDynamicFieldCollectionResource, HdfsSyncSliceTest, FieldAnalysisRequestHandlerTest, TestStressVersions, TestIBSimilarityFactory, TestHashPartitioner, CopyFieldTest, ScriptEngineTest, DisMaxRequestHandlerTest, TestCSVResponseWriter, TestSerializedLuceneMatchVersion, TestCollationField, XsltUpdateRequestHandlerTest, SolrInfoMBeanTest, DocValuesTest, TestDistributedGrouping, StatsComponentTest, BasicZkTest, UnloadDistributedZkTest, TestWriterPerf, OpenCloseCoreStressTest, SynonymTokenizerTest, TestMultiCoreConfBootstrap, TestClassNameShortening, SpellCheckComponentTest, FastVectorHighlighterTest, AlternateDirectoryTest, TestRandomDVFaceting, MoreLikeThisHandlerTest, TestCursorMarkWithoutUniqueKey, WordBreakSolrSpellCheckerTest, TestCopyFieldCollectionResource, TestDFRSimilarityFactory, BadIndexSchemaTest, DeleteReplicaTest, TestElisionMultitermQuery, BlockDirectoryTest, TestCodecSupport, SimpleFacetsTest, TermsComponentTest, TestAddFieldRealTimeGet, LukeRequestHandlerTest, TestCustomSort, TestExtendedDismaxParser, TestJoin, TestRTGBase, ShardRoutingCustomTest, DeleteShardTest, HdfsRecoveryZkTest, TestSolrDeletionPolicy2, OverseerTest, TermVectorComponentDistributedTest, UniqFieldsUpdateProcessorFactoryTest, ParsingFieldUpdateProcessorsTest, PingRequestHandlerTest, TestRandomFaceting, DistributedTermsComponentTest, CursorPagingTest, TestSort, SolrCmdDistributorTest, TestZkChroot, TestTrie, ZkSolrClientTest, ShowFileRequestHandlerTest, SuggesterTSTTest, BlockCacheTest, JsonLoaderTest, TestBinaryResponseWriter, TestFunctionQuery, NotRequiredUniqueKeyTest, URLClassifyProcessorTest, IndexSchemaTest, TimeZoneUtilsTest, TestManagedSchemaFieldResource, DocValuesMultiTest, HdfsUnloadDistributedZkTest, TestQuerySenderNoQuery, RequestHandlersTest, TestSuggestSpellingConverter, TestShardHandlerFactory, ShardRoutingTest, DocumentAnalysisRequestHandlerTest, CacheHeaderTest, HdfsDirectoryTest, CoreAdminCreateDiscoverTest, TestRangeQuery, TestQueryTypes, StandardRequestHandlerTest, MinimalSchemaTest, TestOmitPositions, TestFiltering, HdfsBasicDistributedZkTest, OpenExchangeRatesOrgProviderTest, RecoveryZkTest, AliasIntegrationTest, BasicFunctionalityTest, DirectUpdateHandlerTest, SolrTestCaseJ4Test, BasicDistributedZk2Test, TestSolrQueryParser, SolrRequestParserTest, TestReload, TestPhraseSuggestions, TestLFUCache, QueryResultKeyTest, TestDefaultSearchFieldResource, TestUtils, CachingDirectoryFactoryTest, TestDefaultSimilarityFactory, CoreContainerCoreInitFailuresTest, ReturnFieldsTest, TestDistributedSearch, TestSolrXml, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest]
   [junit4] Completed in 105.64s, 1 test, 1 error <<< FAILURES!

[...truncated 567 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: 76 minutes 22 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.8.0-fcs-b129 -server -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



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

Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/3722/
Java: 32bit/jdk1.7.0_60-ea-b04 -server -XX:+UseSerialGC

1 tests failed.
FAILED:  org.apache.solr.client.solrj.impl.BasicHttpSolrServerTest.testConnectionRefused

Error Message:


Stack Trace:
java.lang.AssertionError
	at __randomizedtesting.SeedInfo.seed([E83D4FD0D76B3054:C794EBC100E47F50]:0)
	at org.junit.Assert.fail(Assert.java:92)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at org.junit.Assert.assertTrue(Assert.java:54)
	at org.apache.solr.client.solrj.impl.BasicHttpSolrServerTest.testConnectionRefused(BasicHttpSolrServerTest.java:158)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:606)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:744)




Build Log:
[...truncated 11525 lines...]
   [junit4] Suite: org.apache.solr.client.solrj.impl.BasicHttpSolrServerTest
   [junit4]   2> 56495 T110 oas.SolrTestCaseJ4.buildSSLConfig Randomized ssl (true) and clientAuth (false)
   [junit4]   2> 56495 T110 oas.SolrTestCaseJ4.initCore ####initCore
   [junit4]   2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\.\solrtest-BasicHttpSolrServerTest-1392858868323
   [junit4]   2> 56496 T110 oas.SolrTestCaseJ4.initCore ####initCore end
   [junit4]   2> 56497 T110 oejs.Server.doStart jetty-8.1.10.v20130312
   [junit4]   2> 56507 T110 oejus.SslContextFactory.doStart Enabled Protocols [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2] of [SSLv2Hello, SSLv3, TLSv1, TLSv1.1, TLSv1.2]
   [junit4]   2> 56514 T110 oejs.AbstractConnector.doStart Started SslSelectChannelConnector@127.0.0.1:50952
   [junit4]   2> 56548 T110 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
   [junit4]   2> 56548 T110 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
   [junit4]   2> 56548 T110 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr
   [junit4]   2> 56548 T110 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\'
   [junit4]   2> 56581 T110 oasc.ConfigSolr.fromFile Loading container configuration from C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\solr.xml
   [junit4]   2> 56648 T110 oasc.CorePropertiesLocator.<init> Config-defined core root directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr
   [junit4]   2> 56648 T110 oasc.CoreContainer.<init> New CoreContainer 23226952
   [junit4]   2> 56648 T110 oasc.CoreContainer.load Loading cores into CoreContainer [instanceDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\]
   [junit4]   2> 56651 T110 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 0
   [junit4]   2> 56651 T110 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: null
   [junit4]   2> 56651 T110 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 0
   [junit4]   2> 56651 T110 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
   [junit4]   2> 56651 T110 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
   [junit4]   2> 56651 T110 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
   [junit4]   2> 56651 T110 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
   [junit4]   2> 56651 T110 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
   [junit4]   2> 56651 T110 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
   [junit4]   2> 56665 T110 oasl.LogWatcher.createWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
   [junit4]   2> 56665 T110 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
   [junit4]   2> 56665 T110 oasc.CoreContainer.load Host Name: 
   [junit4]   2> 56668 T110 oasc.CorePropertiesLocator.discover Looking for core definitions underneath C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr
   [junit4]   2> 56689 T110 oasc.CorePropertiesLocator.discoverUnder Found core collection1 in C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\
   [junit4]   2> 56692 T110 oasc.CorePropertiesLocator.discover Found 1 core definitions
   [junit4]   2> 56694 T120 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1
   [junit4]   2> 56695 T120 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\'
   [junit4]   2> 56732 T120 oasc.SolrConfig.initLibs Adding specified lib dirs to ClassLoader
   [junit4]   2> 56733 T120 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/extraction/lib (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\..\..\..\contrib\extraction\lib).
   [junit4]   2> 56734 T120 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\..\..\..\dist).
   [junit4]   2> 56735 T120 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/clustering/lib/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\..\..\..\contrib\clustering\lib).
   [junit4]   2> 56735 T120 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\..\..\..\dist).
   [junit4]   2> 56735 T120 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/langid/lib/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\..\..\..\contrib\langid\lib).
   [junit4]   2> 56735 T120 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\..\..\..\dist).
   [junit4]   2> 56735 T120 oasc.SolrResourceLoader.addToClassLoader WARN No files added to classloader from lib: ../../../contrib/velocity/lib (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\..\..\..\contrib\velocity\lib).
   [junit4]   2> 56737 T120 oasc.SolrResourceLoader.addToClassLoader WARN Can't find (or read) directory to add to classloader: ../../../dist/ (resolved as: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\..\..\..\dist).
   [junit4]   2> 56780 T120 oasu.SolrIndexConfig.<init> IndexWriter infoStream solr logging is enabled
   [junit4]   2> 56783 T120 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_48
   [junit4]   2> 56859 T120 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
   [junit4]   2> 56860 T120 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
   [junit4]   2> 56886 T120 oass.IndexSchema.readSchema [collection1] Schema name=example
   [junit4]   2> 57454 T120 oass.IndexSchema.readSchema unique key field: id
   [junit4]   2> 57477 T120 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 57483 T120 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
   [junit4]   2> 57514 T120 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
   [junit4]   2> 57514 T120 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\, dataDir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solrtest-BasicHttpSolrServerTest-1392858868323\
   [junit4]   2> 57515 T120 oasc.JmxMonitoredMap.<init> No JMX servers found, not exposing Solr information with JMX.
   [junit4]   2> 57515 T120 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for newSearcher: org.apache.solr.core.QuerySenderListener{queries=[]}
   [junit4]   2> 57516 T120 oasc.SolrCore.initListeners [collection1] Added SolrEventListener for firstSearcher: org.apache.solr.core.QuerySenderListener{queries=[{q=static firstSearcher warming in solrconfig.xml}]}
   [junit4]   2> 57516 T120 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solrtest-BasicHttpSolrServerTest-1392858868323\
   [junit4]   2> 57516 T120 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solrtest-BasicHttpSolrServerTest-1392858868323\index/
   [junit4]   2> 57516 T120 oasc.SolrCore.initIndex WARN [collection1] Solr index directory 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solrtest-BasicHttpSolrServerTest-1392858868323\index' doesn't exist. Creating new index...
   [junit4]   2> 57517 T120 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solrtest-BasicHttpSolrServerTest-1392858868323\index
   [junit4]   2> 57518 T120 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-52-thread-1]: init: current segments file is "null"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@12c5486
   [junit4]   2> 57518 T120 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-52-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
   [junit4]   2> 57518 T120 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-52-thread-1]: 0 msec to checkpoint
   [junit4]   2> 57518 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]: init: create=true
   [junit4]   2> 57518 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]: 
   [junit4]   2> 	dir=MockDirectoryWrapper(RAMDirectory@1c1668f lockFactory=NativeFSLockFactory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solrtest-BasicHttpSolrServerTest-1392858868323\index)
   [junit4]   2> 	index=
   [junit4]   2> 	version=4.8-SNAPSHOT
   [junit4]   2> 	matchVersion=LUCENE_48
   [junit4]   2> 	analyzer=null
   [junit4]   2> 	ramBufferSizeMB=100.0
   [junit4]   2> 	maxBufferedDocs=-1
   [junit4]   2> 	maxBufferedDeleteTerms=-1
   [junit4]   2> 	mergedSegmentWarmer=null
   [junit4]   2> 	readerTermsIndexDivisor=1
   [junit4]   2> 	termIndexInterval=32
   [junit4]   2> 	delPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper
   [junit4]   2> 	commit=null
   [junit4]   2> 	openMode=CREATE
   [junit4]   2> 	similarity=org.apache.lucene.search.similarities.DefaultSimilarity
   [junit4]   2> 	mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=1, maxMergeCount=2, mergeThreadPriority=-1
   [junit4]   2> 	default WRITE_LOCK_TIMEOUT=1000
   [junit4]   2> 	writeLockTimeout=1000
   [junit4]   2> 	codec=Lucene46
   [junit4]   2> 	infoStream=org.apache.solr.update.LoggingInfoStream
   [junit4]   2> 	mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 	indexerThreadPool=org.apache.lucene.index.ThreadAffinityDocumentsWriterThreadPool@1615e55
   [junit4]   2> 	readerPooling=false
   [junit4]   2> 	perThreadHardLimitMB=1945
   [junit4]   2> 	useCompoundFile=false
   [junit4]   2> 	
   [junit4]   2> 57518 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]: now flush at close waitForMerges=true
   [junit4]   2> 57518 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]:   start flush: applyAllDeletes=true
   [junit4]   2> 57518 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]:   index before flush 
   [junit4]   2> 57518 T120 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-52-thread-1]: coreLoadExecutor-52-thread-1 startFullFlush
   [junit4]   2> 57518 T120 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-52-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 57520 T120 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-52-thread-1]: coreLoadExecutor-52-thread-1 finishFullFlush success=true
   [junit4]   2> 57520 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]: apply all deletes during flush
   [junit4]   2> 57521 T120 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-52-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@1782656 minGen=9223372036854775807 packetCount=0
   [junit4]   2> 57521 T120 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-52-thread-1]: now merge
   [junit4]   2> 57521 T120 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-52-thread-1]:   index: 
   [junit4]   2> 57521 T120 oasu.LoggingInfoStream.message [CMS][coreLoadExecutor-52-thread-1]:   no more merges pending; now return
   [junit4]   2> 57521 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]: waitForMerges
   [junit4]   2> 57521 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]: waitForMerges done
   [junit4]   2> 57521 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]: now call final commit()
   [junit4]   2> 57521 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]: commit: start
   [junit4]   2> 57521 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]: commit: enter lock
   [junit4]   2> 57521 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]: commit: now prepare
   [junit4]   2> 57521 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]: prepareCommit: flush
   [junit4]   2> 57521 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]:   index before flush 
   [junit4]   2> 57521 T120 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-52-thread-1]: coreLoadExecutor-52-thread-1 startFullFlush
   [junit4]   2> 57521 T120 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-52-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 57523 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]: apply all deletes during flush
   [junit4]   2> 57523 T120 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-52-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@1782656 minGen=9223372036854775807 packetCount=0
   [junit4]   2> 57523 T120 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-52-thread-1]: coreLoadExecutor-52-thread-1 finishFullFlush success=true
   [junit4]   2> 57523 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]: startCommit(): start
   [junit4]   2> 57523 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]: startCommit index= changeCount=1
   [junit4]   2> 57523 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]: done all syncs: []
   [junit4]   2> 57523 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]: commit: pendingCommit != null
   [junit4]   2> 57523 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]: commit: wrote segments file "segments_1"
   [junit4]   2> 57524 T120 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-52-thread-1]: now checkpoint "" [0 segments ; isCommit = true]
   [junit4]   2> 57524 T120 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1c1668f lockFactory=NativeFSLockFactory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solrtest-BasicHttpSolrServerTest-1392858868323\index),segFN=segments_1,generation=1}
   [junit4]   2> 57524 T120 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 57525 T120 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-52-thread-1]: 0 msec to checkpoint
   [junit4]   2> 57525 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]: commit: done
   [junit4]   2> 57525 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]: at close: 
   [junit4]   2> 57526 T120 oasc.SolrCore.initWriters created json: solr.JSONResponseWriter
   [junit4]   2> 57526 T120 oasc.SolrCore.initWriters adding lazy queryResponseWriter: solr.VelocityResponseWriter
   [junit4]   2> 57526 T120 oasc.SolrCore.initWriters created velocity: solr.VelocityResponseWriter
   [junit4]   2> 57527 T120 oasc.SolrCore.initWriters created xslt: solr.XSLTResponseWriter
   [junit4]   2> 57527 T120 oasr.XSLTResponseWriter.init xsltCacheLifetimeSeconds=5
   [junit4]   2> 57528 T120 oasc.SolrCore.loadUpdateProcessorChains no updateRequestProcessorChain defined as default, creating implicit default
   [junit4]   2> 57528 T120 oasc.RequestHandlers.initHandlersFromConfig created /select: solr.SearchHandler
   [junit4]   2> 57528 T120 oasc.RequestHandlers.initHandlersFromConfig created /query: solr.SearchHandler
   [junit4]   2> 57529 T120 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
   [junit4]   2> 57529 T120 oasc.RequestHandlers.initHandlersFromConfig created /browse: solr.SearchHandler
   [junit4]   2> 57530 T120 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
   [junit4]   2> 57530 T120 oasc.RequestHandlers.initHandlersFromConfig created /update/json: solr.UpdateRequestHandler
   [junit4]   2> 57530 T120 oasc.RequestHandlers.initHandlersFromConfig created /update/csv: solr.UpdateRequestHandler
   [junit4]   2> 57530 T120 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.extraction.ExtractingRequestHandler
   [junit4]   2> 57530 T120 oasc.RequestHandlers.initHandlersFromConfig created /update/extract: solr.extraction.ExtractingRequestHandler
   [junit4]   2> 57530 T120 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.FieldAnalysisRequestHandler
   [junit4]   2> 57530 T120 oasc.RequestHandlers.initHandlersFromConfig created /analysis/field: solr.FieldAnalysisRequestHandler
   [junit4]   2> 57530 T120 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.DocumentAnalysisRequestHandler
   [junit4]   2> 57530 T120 oasc.RequestHandlers.initHandlersFromConfig created /analysis/document: solr.DocumentAnalysisRequestHandler
   [junit4]   2> 57532 T120 oasc.RequestHandlers.initHandlersFromConfig created /admin/: solr.admin.AdminHandlers
   [junit4]   2> 57532 T120 oasc.RequestHandlers.initHandlersFromConfig created /admin/ping: solr.PingRequestHandler
   [junit4]   2> 57532 T120 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
   [junit4]   2> 57532 T120 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
   [junit4]   2> 57532 T120 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 57532 T120 oasc.RequestHandlers.initHandlersFromConfig created /spell: solr.SearchHandler
   [junit4]   2> 57532 T120 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 57532 T120 oasc.RequestHandlers.initHandlersFromConfig created /suggest: solr.SearchHandler
   [junit4]   2> 57532 T120 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 57532 T120 oasc.RequestHandlers.initHandlersFromConfig created /tvrh: solr.SearchHandler
   [junit4]   2> 57532 T120 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 57532 T120 oasc.RequestHandlers.initHandlersFromConfig created /terms: solr.SearchHandler
   [junit4]   2> 57532 T120 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.SearchHandler
   [junit4]   2> 57532 T120 oasc.RequestHandlers.initHandlersFromConfig created /elevate: solr.SearchHandler
   [junit4]   2> 57543 T120 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 57545 T120 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 57547 T120 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
   [junit4]   2> 57553 T120 oasu.CommitTracker.<init> Hard AutoCommit: if uncommited for 15000ms; 
   [junit4]   2> 57553 T120 oasu.CommitTracker.<init> Soft AutoCommit: disabled
   [junit4]   2> 57555 T120 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-52-thread-1]: init: current segments file is "segments_1"; deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@12c5486
   [junit4]   2> 57555 T120 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-52-thread-1]: init: load commit "segments_1"
   [junit4]   2> 57555 T120 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
   [junit4]   2> 		commit{dir=MockDirectoryWrapper(RAMDirectory@1c1668f lockFactory=NativeFSLockFactory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solrtest-BasicHttpSolrServerTest-1392858868323\index),segFN=segments_1,generation=1}
   [junit4]   2> 57555 T120 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
   [junit4]   2> 57556 T120 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-52-thread-1]: now checkpoint "" [0 segments ; isCommit = false]
   [junit4]   2> 57556 T120 oasu.LoggingInfoStream.message [IFD][coreLoadExecutor-52-thread-1]: 0 msec to checkpoint
   [junit4]   2> 57556 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]: init: create=false
   [junit4]   2> 57556 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]: 
   [junit4]   2> 	dir=MockDirectoryWrapper(RAMDirectory@1c1668f lockFactory=NativeFSLockFactory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solrtest-BasicHttpSolrServerTest-1392858868323\index)
   [junit4]   2> 	index=
   [junit4]   2> 	version=4.8-SNAPSHOT
   [junit4]   2> 	matchVersion=LUCENE_48
   [junit4]   2> 	analyzer=null
   [junit4]   2> 	ramBufferSizeMB=100.0
   [junit4]   2> 	maxBufferedDocs=-1
   [junit4]   2> 	maxBufferedDeleteTerms=-1
   [junit4]   2> 	mergedSegmentWarmer=null
   [junit4]   2> 	readerTermsIndexDivisor=1
   [junit4]   2> 	termIndexInterval=32
   [junit4]   2> 	delPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper
   [junit4]   2> 	commit=null
   [junit4]   2> 	openMode=APPEND
   [junit4]   2> 	similarity=org.apache.lucene.search.similarities.DefaultSimilarity
   [junit4]   2> 	mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=1, maxMergeCount=2, mergeThreadPriority=-1
   [junit4]   2> 	default WRITE_LOCK_TIMEOUT=1000
   [junit4]   2> 	writeLockTimeout=1000
   [junit4]   2> 	codec=Lucene46
   [junit4]   2> 	infoStream=org.apache.solr.update.LoggingInfoStream
   [junit4]   2> 	mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0
   [junit4]   2> 	indexerThreadPool=org.apache.lucene.index.ThreadAffinityDocumentsWriterThreadPool@a4f27a
   [junit4]   2> 	readerPooling=false
   [junit4]   2> 	perThreadHardLimitMB=1945
   [junit4]   2> 	useCompoundFile=false
   [junit4]   2> 	
   [junit4]   2> 57556 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]: flush at getReader
   [junit4]   2> 57556 T120 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-52-thread-1]: coreLoadExecutor-52-thread-1 startFullFlush
   [junit4]   2> 57556 T120 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-52-thread-1]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 57556 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]: apply all deletes during flush
   [junit4]   2> 57556 T120 oasu.LoggingInfoStream.message [BD][coreLoadExecutor-52-thread-1]: prune sis=org.apache.lucene.index.SegmentInfos@12b5821 minGen=9223372036854775807 packetCount=0
   [junit4]   2> 57556 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]: return reader version=1 reader=StandardDirectoryReader(segments_1:1:nrt)
   [junit4]   2> 57558 T120 oasu.LoggingInfoStream.message [DW][coreLoadExecutor-52-thread-1]: coreLoadExecutor-52-thread-1 finishFullFlush success=true
   [junit4]   2> 57558 T120 oasu.LoggingInfoStream.message [IW][coreLoadExecutor-52-thread-1]: getReader took 2 msec
   [junit4]   2> 57558 T120 oass.SolrIndexSearcher.<init> Opening Searcher@17506e6[collection1] main
   [junit4]   2> 57558 T120 oashc.SpellCheckComponent.inform Initializing spell checkers
   [junit4]   2> 57558 T120 oass.DirectSolrSpellChecker.init init: {name=default,field=text,classname=solr.DirectSolrSpellChecker,distanceMeasure=internal,accuracy=0.5,maxEdits=2,minPrefix=1,maxInspections=5,minQueryLength=4,maxQueryFrequency=0.01}
   [junit4]   2> 57564 T120 oashc.SpellCheckComponent.inform No queryConverter defined, using default converter
   [junit4]   2> 57564 T120 oashc.SuggestComponent.inform Initializing SuggestComponent
   [junit4]   2> 57564 T120 oasss.SolrSuggester.init init: {name=mySuggester,lookupImpl=FuzzyLookupFactory,dictionaryImpl=DocumentDictionaryFactory,field=cat,weightField=price,suggestAnalyzerFieldType=string}
   [junit4]   2> 57565 T120 oasss.SolrSuggester.init Dictionary loaded with params: {name=mySuggester,lookupImpl=FuzzyLookupFactory,dictionaryImpl=DocumentDictionaryFactory,field=cat,weightField=price,suggestAnalyzerFieldType=string}
   [junit4]   2> 57565 T120 oashc.QueryElevationComponent.inform Loading QueryElevation from: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\example\solr\collection1\conf\elevate.xml
   [junit4]   2> 57598 T120 oash.ReplicationHandler.inform Commits will be reserved for  10000
   [junit4]   2> 57599 T120 oasc.CoreContainer.registerCore registering core: collection1
   [junit4]   2> 57599 T121 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@17506e6[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 57599 T110 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0
   [junit4]   2> 57600 T110 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
   [junit4]   2> 57600 T110 oas.SolrJettyTestBase.createJetty Jetty Assigned Port#50952
   [junit4]   2> ASYNC  NEW_CORE C49 name=collection1 org.apache.solr.core.SolrCore@1bdb793
   [junit4]   2> 57600 T121 C49 oasc.SolrCore.execute [collection1] webapp=null path=null params={event=firstSearcher&q=static+firstSearcher+warming+in+solrconfig.xml&distrib=false} hits=0 status=0 QTime=1 
   [junit4]   2> 57601 T121 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
   [junit4]   2> 57601 T121 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: default
   [junit4]   2> 57601 T121 oashc.SpellCheckComponent$SpellCheckerListener.newSearcher Loading spell index for spellchecker: wordbreak
   [junit4]   2> 57601 T121 oashc.SuggestComponent$SuggesterListener.newSearcher Loading suggester index for: mySuggester
   [junit4]   2> 57601 T121 oasss.SolrSuggester.reload reload()
   [junit4]   2> 57601 T121 oasss.SolrSuggester.build build()
   [junit4]   2> 57608 T121 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@17506e6[collection1] main{StandardDirectoryReader(segments_1:1:nrt)}
   [junit4]   2> 57611 T110 oas.SolrTestCaseJ4.setUp ###Starting testGetRawStream
   [junit4]   2> 57663 T113 C49 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={} hits=0 status=0 QTime=0 
   [junit4]   2> 57666 T110 oas.SolrTestCaseJ4.tearDown ###Ending testGetRawStream
   [junit4]   2> 57674 T110 oas.SolrTestCaseJ4.setUp ###Starting testConnectionRefused
   [junit4]   2> 58146 T110 oas.SolrTestCaseJ4.tearDown ###Ending testConnectionRefused
   [junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=BasicHttpSolrServerTest -Dtests.method=testConnectionRefused -Dtests.seed=E83D4FD0D76B3054 -Dtests.slow=true -Dtests.locale=es_PY -Dtests.timezone=America/Cambridge_Bay -Dtests.file.encoding=ISO-8859-1
   [junit4] FAILURE 0.53s | BasicHttpSolrServerTest.testConnectionRefused <<<
   [junit4]    > Throwable #1: java.lang.AssertionError
   [junit4]    > 	at __randomizedtesting.SeedInfo.seed([E83D4FD0D76B3054:C794EBC100E47F50]:0)
   [junit4]    > 	at org.apache.solr.client.solrj.impl.BasicHttpSolrServerTest.testConnectionRefused(BasicHttpSolrServerTest.java:158)
   [junit4]    > 	at java.lang.Thread.run(Thread.java:744)
   [junit4]   2> 58207 T110 oas.SolrTestCaseJ4.setUp ###Starting testRedirect
   [junit4]   2> 58313 T113 C49 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={wt=javabin&q=*:*&version=2} hits=0 status=0 QTime=1 
   [junit4]   2> 58317 T110 oas.SolrTestCaseJ4.tearDown ###Ending testRedirect
   [junit4]   2> 58327 T110 oas.SolrTestCaseJ4.setUp ###Starting testSetParametersExternalClient
   [junit4]   2> 58330 T110 oas.SolrTestCaseJ4.tearDown ###Ending testSetParametersExternalClient
   [junit4]   2> 58337 T110 oas.SolrTestCaseJ4.setUp ###Starting testSolrExceptionCodeNotFromSolr
   [junit4]   2> 58410 T110 oas.SolrTestCaseJ4.tearDown ###Ending testSolrExceptionCodeNotFromSolr
   [junit4]   1> org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Expected mime type application/octet-stream but got text/html. <html>
   [junit4]   1> <head>
   [junit4]   1> <meta http-equiv="Content-Type" content="text/html;charset=ISO-8859-1"/>
   [junit4]   1> <title>Error 527 527</title>
   [junit4]   1> </head>
   [junit4]   1> <body>
   [junit4]   1> <h2>HTTP ERROR: 527</h2>
   [junit4]   1> <p>Problem accessing /solr/debug/foo/select. Reason:
   [junit4]   1> <pre>    527</pre></p>
   [junit4]   1> <hr /><i><small>Powered by Jetty://</small></i>
   [junit4]   1>                                                 
   [junit4]   1>                                                 
   [junit4]   1>                                                 
   [junit4]   1>                                                 
   [junit4]   1>                                                 
   [junit4]   1>                                                 
   [junit4]   1>                                                 
   [junit4]   1>                                                 
   [junit4]   1>                                                 
   [junit4]   1>                                                 
   [junit4]   1>                                                 
   [junit4]   1>                                                 
   [junit4]   1>                                                 
   [junit4]   1>                                                 
   [junit4]   1>                                                 
   [junit4]   1>                                                 
   [junit4]   1>                                                 
   [junit4]   1>                                                 
   [junit4]   1>                                                 
   [junit4]   1>                                                 
   [junit4]   1> </body>
   [junit4]   1> </html>
   [junit4]   1> 
   [junit4]   2> 58418 T110 oas.SolrTestCaseJ4.setUp ###Starting testExampleKeystorePath
   [junit4]   2> 58419 T110 oas.SolrTestCaseJ4.tearDown ###Ending testExampleKeystorePath
   [junit4]   2> 58425 T110 oas.SolrTestCaseJ4.setUp ###Starting testTimeout
   [junit4]   2> 60346 T110 oas.SolrTestCaseJ4.tearDown ###Ending testTimeout
   [junit4]   2> 60354 T110 oas.SolrTestCaseJ4.setUp ###Starting testUpdate
   [junit4]   2> 60414 T110 oas.SolrTestCaseJ4.tearDown ###Ending testUpdate
   [junit4]   2> 60422 T110 oas.SolrTestCaseJ4.setUp ###Starting testDelete
   [junit4]   2> 60484 T110 oas.SolrTestCaseJ4.tearDown ###Ending testDelete
   [junit4]   2> 60492 T110 oas.SolrTestCaseJ4.setUp ###Starting testQuery
   [junit4]   2> 60551 T110 oas.SolrTestCaseJ4.tearDown ###Ending testQuery
   [junit4]   2> 60560 T110 oas.SolrTestCaseJ4.setUp ###Starting testCompression
   [junit4]   2> ASYNC  NEW_CORE C50 name=collection1 org.apache.solr.core.SolrCore@1bdb793
   [junit4]   2> 60703 T118 C50 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={wt=xml&q=foo} hits=0 status=0 QTime=1 
   [junit4]   2> 60757 T118 C50 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={wt=javabin&q=foo&version=2} hits=0 status=0 QTime=1 
   [junit4]   2> 60763 T110 oas.SolrTestCaseJ4.tearDown ###Ending testCompression
   [junit4]   2> 60776 T110 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=23226952
   [junit4]   2> 60777 T110 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@1bdb793
   [junit4]   2> 60777 T110 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommit maxTime=15000ms,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=0}
   [junit4]   2> 60777 T110 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
   [junit4]   2> 60777 T110 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
   [junit4]   2> 60777 T110 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
   [junit4]   2> 60779 T110 C50 oasu.LoggingInfoStream.message [IW][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]: now flush at close waitForMerges=true
   [junit4]   2> 60779 T110 C50 oasu.LoggingInfoStream.message [IW][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]:   start flush: applyAllDeletes=true
   [junit4]   2> 60779 T110 C50 oasu.LoggingInfoStream.message [IW][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]:   index before flush 
   [junit4]   2> 60779 T110 C50 oasu.LoggingInfoStream.message [DW][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]: SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker startFullFlush
   [junit4]   2> 60781 T110 C50 oasu.LoggingInfoStream.message [DW][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 60781 T110 C50 oasu.LoggingInfoStream.message [DW][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]: SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker finishFullFlush success=true
   [junit4]   2> 60781 T110 C50 oasu.LoggingInfoStream.message [IW][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]: apply all deletes during flush
   [junit4]   2> 60782 T110 C50 oasu.LoggingInfoStream.message [BD][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@12b5821 minGen=9223372036854775807 packetCount=0
   [junit4]   2> 60782 T110 C50 oasu.LoggingInfoStream.message [CMS][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]: now merge
   [junit4]   2> 60782 T110 C50 oasu.LoggingInfoStream.message [CMS][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]:   index: 
   [junit4]   2> 60782 T110 C50 oasu.LoggingInfoStream.message [CMS][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]:   no more merges pending; now return
   [junit4]   2> 60782 T110 C50 oasu.LoggingInfoStream.message [IW][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]: waitForMerges
   [junit4]   2> 60782 T110 C50 oasu.LoggingInfoStream.message [IW][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]: waitForMerges done
   [junit4]   2> 60782 T110 C50 oasu.LoggingInfoStream.message [IW][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]: now call final commit()
   [junit4]   2> 60782 T110 C50 oasu.LoggingInfoStream.message [IW][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]: commit: start
   [junit4]   2> 60782 T110 C50 oasu.LoggingInfoStream.message [IW][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]: commit: enter lock
   [junit4]   2> 60782 T110 C50 oasu.LoggingInfoStream.message [IW][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]: commit: now prepare
   [junit4]   2> 60782 T110 C50 oasu.LoggingInfoStream.message [IW][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]: prepareCommit: flush
   [junit4]   2> 60783 T110 C50 oasu.LoggingInfoStream.message [IW][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]:   index before flush 
   [junit4]   2> 60783 T110 C50 oasu.LoggingInfoStream.message [DW][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]: SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker startFullFlush
   [junit4]   2> 60783 T110 C50 oasu.LoggingInfoStream.message [DW][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]: anyChanges? numDocsInRam=0 deletes=false hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 60783 T110 C50 oasu.LoggingInfoStream.message [IW][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]: apply all deletes during flush
   [junit4]   2> 60783 T110 C50 oasu.LoggingInfoStream.message [BD][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]: prune sis=org.apache.lucene.index.SegmentInfos@12b5821 minGen=9223372036854775807 packetCount=0
   [junit4]   2> 60783 T110 C50 oasu.LoggingInfoStream.message [DW][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]: SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker finishFullFlush success=true
   [junit4]   2> 60785 T110 C50 oasu.LoggingInfoStream.message [IW][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]: startCommit(): start
   [junit4]   2> 60785 T110 C50 oasu.LoggingInfoStream.message [IW][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]:   skip startCommit(): no changes pending
   [junit4]   2> 60785 T110 C50 oasu.LoggingInfoStream.message [IW][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]: commit: pendingCommit == null; skip
   [junit4]   2> 60785 T110 C50 oasu.LoggingInfoStream.message [IW][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]: commit: done
   [junit4]   2> 60785 T110 C50 oasu.LoggingInfoStream.message [IW][SUITE-BasicHttpSolrServerTest-seed#[E83D4FD0D76B3054]-worker]: at close: 
   [junit4]   2> 60790 T110 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
   [junit4]   2> 60791 T110 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
   [junit4]   2> 60791 T110 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solrtest-BasicHttpSolrServerTest-1392858868323\ [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solrtest-BasicHttpSolrServerTest-1392858868323\;done=false>>]
   [junit4]   2> 60791 T110 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solrtest-BasicHttpSolrServerTest-1392858868323\
   [junit4]   2> 60792 T110 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solrtest-BasicHttpSolrServerTest-1392858868323\index [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solrtest-BasicHttpSolrServerTest-1392858868323\index;done=false>>]
   [junit4]   2> 60792 T110 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-solrj\test\J0\solrtest-BasicHttpSolrServerTest-1392858868323\index
   [junit4]   2> 60792 T110 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/solr,null}
   [junit4]   2> 60846 T110 oas.SolrTestCaseJ4.deleteCore ###deleteCore
   [junit4]   2> NOTE: test params are: codec=Lucene42, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=es_PY, timezone=America/Cambridge_Bay
   [junit4]   2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.7.0_60-ea (32-bit)/cpus=2,threads=1,free=18176024,total=74162176
   [junit4]   2> NOTE: All tests run in this JVM: [TestSpellCheckResponse, TestUpdateRequestCodec, SolrExceptionTest, FieldAnalysisResponseTest, TestXMLEscaping, SolrExampleBinaryTest, SolrExampleStreamingBinaryTest, MultiCoreEmbeddedTest, SolrQueryTest, QueryResponseTest, LargeVolumeEmbeddedTest, BasicHttpSolrServerTest]
   [junit4] Completed in 4.39s, 11 tests, 1 failure <<< FAILURES!

[...truncated 117 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:202: 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: 48 suites, 280 tests, 1 failure

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