[JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.6.0_45) - Build # 6272 - Failure!

classic Classic list List threaded Threaded
1 message Options
Reply | Threaded
Open this post in threaded view
|

[JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.6.0_45) - Build # 6272 - Failure!

Policeman Jenkins Server-2
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/6272/
Java: 64bit/jdk1.6.0_45 -XX:+UseCompressedOops -XX:+UseParallelGC

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

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

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


REGRESSION:  org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.testDistribSearch

Error Message:
Test abandoned because suite timeout was reached.

Stack Trace:
java.lang.Exception: Test abandoned because suite timeout was reached.
        at __randomizedtesting.SeedInfo.seed([D1FD32D6913264B5]:0)




Build Log:
[...truncated 9508 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
[junit4:junit4]   2> 66751 T291 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4]   2> 66760 T291 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./solrtest-ChaosMonkeySafeLeaderTest-1372394478567
[junit4:junit4]   2> 66760 T291 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 66761 T292 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4]   2> 66861 T291 oasc.ZkTestServer.run start zk server on port:50700
[junit4:junit4]   2> 66862 T291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 66865 T298 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@584c4b3e name:ZooKeeperConnection Watcher:127.0.0.1:50700 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 66865 T291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 66865 T291 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 66874 T291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 66876 T300 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6d0e6c33 name:ZooKeeperConnection Watcher:127.0.0.1:50700/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 66877 T291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 66877 T291 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 66880 T291 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 66882 T291 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 66884 T291 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 66887 T291 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 66887 T291 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 66891 T291 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 66892 T291 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 66895 T291 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4]   2> 66895 T291 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 66897 T291 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4]   2> 66898 T291 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 66902 T291 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4]   2> 66903 T291 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 66905 T291 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 66905 T291 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 66908 T291 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 66908 T291 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 66910 T291 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 66911 T291 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 66913 T291 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4]   2> 66913 T291 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 66989 T291 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4]   2> 67005 T291 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:46481
[junit4:junit4]   2> 67006 T291 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 67007 T291 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 67007 T291 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372394478723
[junit4:junit4]   2> 67008 T291 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372394478723/solr.xml
[junit4:junit4]   2> 67008 T291 oasc.CoreContainer.<init> New CoreContainer 340454995
[junit4:junit4]   2> 67009 T291 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372394478723/'
[junit4:junit4]   2> 67009 T291 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372394478723/'
[junit4:junit4]   2> 67077 T291 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 67077 T291 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 67078 T291 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 67078 T291 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 67079 T291 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 67080 T291 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 67080 T291 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 67081 T291 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 67082 T291 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 67082 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 67088 T291 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4]   2> 67089 T291 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50700/solr
[junit4:junit4]   2> 67089 T291 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 67090 T291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 67093 T311 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2f74a57e name:ZooKeeperConnection Watcher:127.0.0.1:50700 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 67096 T291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 67099 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 67104 T291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 67105 T313 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@51f11be1 name:ZooKeeperConnection Watcher:127.0.0.1:50700/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 67106 T291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 67107 T291 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4]   2> 67111 T291 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4]   2> 67115 T291 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 67122 T291 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:46481_
[junit4:junit4]   2> 67123 T291 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:46481_
[junit4:junit4]   2> 67126 T291 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 67169 T291 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 67172 T291 oasc.Overseer.start Overseer (id=89941244547563523-127.0.0.1:46481_-n_0000000000) starting
[junit4:junit4]   2> 67175 T291 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4]   2> 67179 T315 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 67179 T291 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 67182 T291 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4]   2> 67183 T291 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4]   2> 67186 T314 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 67189 T316 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 67190 T316 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 68690 T314 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 68691 T314 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":null,
[junit4:junit4]   2>  "numShards":"1",
[junit4:junit4]   2>  "shard":null,
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"down",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"control_collection",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:46481_",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:46481"}
[junit4:junit4]   2> 68691 T314 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4]   2> 68691 T314 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4]   2> 68695 T313 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 69191 T316 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372394478723/collection1
[junit4:junit4]   2> 69192 T316 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 69193 T316 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 69193 T316 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 69195 T316 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372394478723/collection1/'
[junit4:junit4]   2> 69196 T316 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372394478723/collection1/lib/README' to classloader
[junit4:junit4]   2> 69196 T316 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372394478723/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 69237 T316 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   2> 69271 T316 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 69273 T316 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 69278 T316 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4]   2> 69625 T316 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4]   2> 69627 T316 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4]   2> 69627 T316 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 69634 T316 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 69636 T316 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 69655 T316 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 69658 T316 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 69662 T316 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 69663 T316 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 69663 T316 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 69663 T316 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 69664 T316 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 69665 T316 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 69665 T316 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 69665 T316 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1372394478723/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/control/data/
[junit4:junit4]   2> 69665 T316 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@359ecd80
[junit4:junit4]   2> 69666 T316 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 69666 T316 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/control/data
[junit4:junit4]   2> 69667 T316 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/control/data/index/
[junit4:junit4]   2> 69667 T316 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 69667 T316 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/control/data/index
[junit4:junit4]   2> 69748 T316 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/control/data/index,segFN=segments_1,generation=1}
[junit4:junit4]   2> 69748 T316 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 69750 T316 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 69750 T316 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 69751 T316 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 69751 T316 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 69752 T316 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 69752 T316 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 69752 T316 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 69753 T316 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 69753 T316 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 69755 T316 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 69758 T316 oass.SolrIndexSearcher.<init> Opening Searcher@1793657 main
[junit4:junit4]   2> 69758 T316 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 69759 T316 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 69763 T317 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1793657 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 69764 T316 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 69764 T316 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:46481 collection:control_collection shard:shard1
[junit4:junit4]   2> 69765 T316 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4]   2> 69771 T316 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 69773 T316 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 69773 T316 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 69774 T316 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:46481/collection1/
[junit4:junit4]   2> 69774 T316 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 69774 T316 oasc.SyncStrategy.syncToMe http://127.0.0.1:46481/collection1/ has no replicas
[junit4:junit4]   2> 69775 T316 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:46481/collection1/
[junit4:junit4]   2> 69775 T316 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4]   2> 70199 T314 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 70242 T313 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4]   2> 70281 T316 oasc.ZkController.register We are http://127.0.0.1:46481/collection1/ and leader is http://127.0.0.1:46481/collection1/
[junit4:junit4]   2> 70281 T316 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:46481
[junit4:junit4]   2> 70282 T316 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 70282 T316 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 70282 T316 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 70284 T316 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 70285 T291 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 70285 T291 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 70286 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 70291 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 70293 T291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 70294 T320 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@186b480a name:ZooKeeperConnection Watcher:127.0.0.1:50700/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 70294 T291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 70296 T291 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4]   2> 70299 T291 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 70376 T291 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4]   2> 70378 T291 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:35920
[junit4:junit4]   2> 70379 T291 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 70379 T291 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 70380 T291 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372394482106
[junit4:junit4]   2> 70380 T291 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372394482106/solr.xml
[junit4:junit4]   2> 70381 T291 oasc.CoreContainer.<init> New CoreContainer 1641164597
[junit4:junit4]   2> 70381 T291 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372394482106/'
[junit4:junit4]   2> 70381 T291 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372394482106/'
[junit4:junit4]   2> 70422 T291 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 70423 T291 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 70423 T291 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 70424 T291 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 70424 T291 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 70424 T291 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 70425 T291 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 70425 T291 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 70425 T291 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 70426 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 70429 T291 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4]   2> 70430 T291 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50700/solr
[junit4:junit4]   2> 70430 T291 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 70431 T291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 70433 T331 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8bc713e name:ZooKeeperConnection Watcher:127.0.0.1:50700 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 70434 T291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 70436 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 70439 T291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 70441 T333 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@391416b3 name:ZooKeeperConnection Watcher:127.0.0.1:50700/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 70441 T291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 70445 T291 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4]   2> 71449 T291 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35920_
[junit4:junit4]   2> 71450 T291 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:35920_
[junit4:junit4]   2> 71454 T333 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 71454 T313 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 71454 T320 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 71455 T313 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 71459 T334 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 71460 T334 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 71748 T314 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 71749 T314 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":"127.0.0.1:46481__collection1",
[junit4:junit4]   2>  "numShards":"1",
[junit4:junit4]   2>  "shard":"shard1",
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"active",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"control_collection",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:46481_",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:46481"}
[junit4:junit4]   2> 71753 T314 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":null,
[junit4:junit4]   2>  "numShards":"3",
[junit4:junit4]   2>  "shard":null,
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"down",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:35920_",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:35920"}
[junit4:junit4]   2> 71753 T314 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 3
[junit4:junit4]   2> 71754 T314 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4]   2> 71796 T320 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 71796 T333 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 71796 T313 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 72461 T334 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372394482106/collection1
[junit4:junit4]   2> 72462 T334 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 72463 T334 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 72463 T334 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 72465 T334 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372394482106/collection1/'
[junit4:junit4]   2> 72466 T334 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372394482106/collection1/lib/README' to classloader
[junit4:junit4]   2> 72466 T334 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372394482106/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 72506 T334 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   2> 72553 T334 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 72554 T334 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 72561 T334 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4]   2> 72892 T334 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4]   2> 72893 T334 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4]   2> 72894 T334 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 72905 T334 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 72909 T334 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 72929 T334 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 72934 T334 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 72939 T334 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 72940 T334 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 72941 T334 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 72941 T334 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 72943 T334 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 72943 T334 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 72943 T334 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 72944 T334 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1372394482106/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty1/
[junit4:junit4]   2> 72944 T334 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@359ecd80
[junit4:junit4]   2> 72945 T334 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 72946 T334 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty1
[junit4:junit4]   2> 72946 T334 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty1/index/
[junit4:junit4]   2> 72947 T334 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 72947 T334 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty1/index
[junit4:junit4]   2> 72987 T334 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty1/index,segFN=segments_1,generation=1}
[junit4:junit4]   2> 72987 T334 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 72989 T334 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 72990 T334 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 72990 T334 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 72991 T334 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 72991 T334 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 72992 T334 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 72992 T334 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 72992 T334 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 72993 T334 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 72995 T334 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 72998 T334 oass.SolrIndexSearcher.<init> Opening Searcher@ac82d1f main
[junit4:junit4]   2> 72998 T334 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 72999 T334 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 73003 T335 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@ac82d1f main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 73005 T334 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 73005 T334 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:35920 collection:collection1 shard:shard1
[junit4:junit4]   2> 73006 T334 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 73014 T334 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 73016 T334 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 73017 T334 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 73017 T334 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:35920/collection1/
[junit4:junit4]   2> 73017 T334 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 73017 T334 oasc.SyncStrategy.syncToMe http://127.0.0.1:35920/collection1/ has no replicas
[junit4:junit4]   2> 73018 T334 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:35920/collection1/
[junit4:junit4]   2> 73018 T334 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 73303 T314 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 73311 T320 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 73311 T333 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 73311 T313 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 73324 T334 oasc.ZkController.register We are http://127.0.0.1:35920/collection1/ and leader is http://127.0.0.1:35920/collection1/
[junit4:junit4]   2> 73325 T334 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:35920
[junit4:junit4]   2> 73325 T334 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 73325 T334 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 73325 T334 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 73327 T334 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 73328 T291 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 73329 T291 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 73330 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 73408 T291 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4]   2> 73412 T291 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:40779
[junit4:junit4]   2> 73413 T291 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 73413 T291 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 73414 T291 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372394485142
[junit4:junit4]   2> 73414 T291 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372394485142/solr.xml
[junit4:junit4]   2> 73415 T291 oasc.CoreContainer.<init> New CoreContainer 341369292
[junit4:junit4]   2> 73416 T291 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372394485142/'
[junit4:junit4]   2> 73416 T291 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372394485142/'
[junit4:junit4]   2> 73471 T291 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 73472 T291 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 73472 T291 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 73472 T291 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 73473 T291 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 73473 T291 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 73473 T291 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 73474 T291 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 73474 T291 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 73474 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 73478 T291 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4]   2> 73478 T291 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50700/solr
[junit4:junit4]   2> 73479 T291 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 73480 T291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 73481 T347 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4e09f33d name:ZooKeeperConnection Watcher:127.0.0.1:50700 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 73482 T291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 73487 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 73493 T291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 73495 T349 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3033e3e0 name:ZooKeeperConnection Watcher:127.0.0.1:50700/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 73495 T291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 73500 T291 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4]   2> 74505 T291 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:40779_
[junit4:junit4]   2> 74506 T291 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:40779_
[junit4:junit4]   2> 74510 T333 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4]   2> 74510 T320 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 74510 T313 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 74511 T313 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 74511 T349 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 74510 T320 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 74518 T333 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 74518 T350 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 74519 T350 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 74817 T314 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 74818 T314 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":"127.0.0.1:35920__collection1",
[junit4:junit4]   2>  "numShards":"3",
[junit4:junit4]   2>  "shard":"shard1",
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"active",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:35920_",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:35920"}
[junit4:junit4]   2> 74822 T314 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":null,
[junit4:junit4]   2>  "numShards":"3",
[junit4:junit4]   2>  "shard":null,
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"down",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:40779_",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:40779"}
[junit4:junit4]   2> 74823 T314 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4]   2> 74823 T314 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4]   2> 74886 T333 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 74886 T349 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 74886 T313 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 74886 T320 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 75520 T350 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372394485142/collection1
[junit4:junit4]   2> 75521 T350 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 75521 T350 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 75522 T350 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 75523 T350 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372394485142/collection1/'
[junit4:junit4]   2> 75524 T350 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372394485142/collection1/lib/README' to classloader
[junit4:junit4]   2> 75524 T350 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372394485142/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 75567 T350 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   2> 75597 T350 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 75599 T350 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 75603 T350 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4]   2> 75944 T350 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4]   2> 75945 T350 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4]   2> 75946 T350 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 75963 T350 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 75971 T350 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 75987 T350 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 75994 T350 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 76022 T350 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 76023 T350 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 76024 T350 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 76024 T350 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 76025 T350 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 76026 T350 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 76026 T350 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 76026 T350 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1372394485142/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty2/
[junit4:junit4]   2> 76027 T350 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@359ecd80
[junit4:junit4]   2> 76028 T350 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 76028 T350 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty2
[junit4:junit4]   2> 76029 T350 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty2/index/
[junit4:junit4]   2> 76029 T350 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 76029 T350 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty2/index
[junit4:junit4]   2> 76037 T350 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty2/index,segFN=segments_1,generation=1}
[junit4:junit4]   2> 76037 T350 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 76039 T350 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 76040 T350 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 76040 T350 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 76041 T350 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 76042 T350 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 76042 T350 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 76042 T350 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 76043 T350 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 76043 T350 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 76045 T350 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 76048 T350 oass.SolrIndexSearcher.<init> Opening Searcher@28ac3f94 main
[junit4:junit4]   2> 76048 T350 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 76049 T350 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 76053 T351 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@28ac3f94 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 76055 T350 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 76055 T350 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:40779 collection:collection1 shard:shard2
[junit4:junit4]   2> 76056 T350 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   2> 76063 T350 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 76069 T350 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 76069 T350 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 76069 T350 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:40779/collection1/
[junit4:junit4]   2> 76070 T350 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 76070 T350 oasc.SyncStrategy.syncToMe http://127.0.0.1:40779/collection1/ has no replicas
[junit4:junit4]   2> 76070 T350 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:40779/collection1/
[junit4:junit4]   2> 76071 T350 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 76394 T314 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 76404 T320 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 76404 T313 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 76404 T349 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 76404 T333 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 76430 T350 oasc.ZkController.register We are http://127.0.0.1:40779/collection1/ and leader is http://127.0.0.1:40779/collection1/
[junit4:junit4]   2> 76431 T350 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:40779
[junit4:junit4]   2> 76431 T350 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 76431 T350 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 76431 T350 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 76556 T350 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 76558 T291 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 76558 T291 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 76559 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 76626 T291 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4]   2> 76629 T291 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:36518
[junit4:junit4]   2> 76630 T291 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 76630 T291 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 76631 T291 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372394488369
[junit4:junit4]   2> 76631 T291 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372394488369/solr.xml
[junit4:junit4]   2> 76631 T291 oasc.CoreContainer.<init> New CoreContainer 498628406
[junit4:junit4]   2> 76632 T291 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372394488369/'
[junit4:junit4]   2> 76632 T291 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372394488369/'
[junit4:junit4]   2> 76676 T291 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 76676 T291 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 76677 T291 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 76677 T291 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 76677 T291 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 76678 T291 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 76678 T291 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 76678 T291 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 76679 T291 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 76679 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 76682 T291 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4]   2> 76683 T291 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50700/solr
[junit4:junit4]   2> 76683 T291 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 76684 T291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 76687 T363 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@50b742d3 name:ZooKeeperConnection Watcher:127.0.0.1:50700 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 76687 T291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 76689 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 76692 T291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 76694 T365 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4900269d name:ZooKeeperConnection Watcher:127.0.0.1:50700/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 76694 T291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 76698 T291 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4]   2> 77701 T291 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36518_
[junit4:junit4]   2> 77702 T291 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36518_
[junit4:junit4]   2> 77705 T333 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 77705 T320 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 77705 T349 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4]   2> 77706 T320 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 77705 T365 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 77706 T313 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 77707 T313 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 77708 T333 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 77710 T349 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 77714 T366 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 77715 T366 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 77909 T314 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 77910 T314 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":"127.0.0.1:40779__collection1",
[junit4:junit4]   2>  "numShards":"3",
[junit4:junit4]   2>  "shard":"shard2",
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"active",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:40779_",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:40779"}
[junit4:junit4]   2> 77913 T314 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":null,
[junit4:junit4]   2>  "numShards":"3",
[junit4:junit4]   2>  "shard":null,
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"down",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:36518_",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:36518"}
[junit4:junit4]   2> 77914 T314 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4]   2> 77914 T314 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard3
[junit4:junit4]   2> 77921 T365 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 77922 T333 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 77921 T349 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 77921 T313 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 77921 T320 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 78716 T366 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372394488369/collection1
[junit4:junit4]   2> 78717 T366 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 78717 T366 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 78718 T366 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 78719 T366 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372394488369/collection1/'
[junit4:junit4]   2> 78719 T366 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372394488369/collection1/lib/README' to classloader
[junit4:junit4]   2> 78720 T366 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372394488369/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 78747 T366 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   2> 78779 T366 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 78780 T366 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 78785 T366 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4]   2> 79102 T366 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4]   2> 79103 T366 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4]   2> 79104 T366 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 79111 T366 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 79113 T366 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 79127 T366 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 79130 T366 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 79133 T366 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 79134 T366 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 79134 T366 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 79134 T366 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 79135 T366 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 79135 T366 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 79136 T366 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 79136 T366 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1372394488369/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty3/
[junit4:junit4]   2> 79136 T366 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@359ecd80
[junit4:junit4]   2> 79137 T366 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 79137 T366 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty3
[junit4:junit4]   2> 79137 T366 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty3/index/
[junit4:junit4]   2> 79138 T366 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 79138 T366 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty3/index
[junit4:junit4]   2> 79141 T366 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty3/index,segFN=segments_1,generation=1}
[junit4:junit4]   2> 79141 T366 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 79143 T366 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 79143 T366 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 79144 T366 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 79144 T366 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 79145 T366 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 79145 T366 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 79145 T366 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 79146 T366 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 79146 T366 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 79148 T366 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 79151 T366 oass.SolrIndexSearcher.<init> Opening Searcher@1c527179 main
[junit4:junit4]   2> 79151 T366 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 79152 T366 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 79157 T367 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1c527179 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 79159 T366 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 79159 T366 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:36518 collection:collection1 shard:shard3
[junit4:junit4]   2> 79160 T366 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4:junit4]   2> 79166 T366 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 79168 T366 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 79169 T366 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 79169 T366 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:36518/collection1/
[junit4:junit4]   2> 79169 T366 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 79169 T366 oasc.SyncStrategy.syncToMe http://127.0.0.1:36518/collection1/ has no replicas
[junit4:junit4]   2> 79170 T366 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:36518/collection1/
[junit4:junit4]   2> 79170 T366 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4:junit4]   2> 79428 T314 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 79436 T349 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 79437 T365 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 79437 T320 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 79437 T313 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 79436 T333 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 79475 T366 oasc.ZkController.register We are http://127.0.0.1:36518/collection1/ and leader is http://127.0.0.1:36518/collection1/
[junit4:junit4]   2> 79475 T366 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:36518
[junit4:junit4]   2> 79475 T366 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 79476 T366 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 79476 T366 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 79478 T366 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 79479 T291 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 79479 T291 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 79480 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 79584 T291 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4]   2> 79587 T291 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:33227
[junit4:junit4]   2> 79588 T291 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 79588 T291 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 79589 T291 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372394491292
[junit4:junit4]   2> 79589 T291 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372394491292/solr.xml
[junit4:junit4]   2> 79589 T291 oasc.CoreContainer.<init> New CoreContainer 2127477083
[junit4:junit4]   2> 79590 T291 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372394491292/'
[junit4:junit4]   2> 79590 T291 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372394491292/'
[junit4:junit4]   2> 79635 T291 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 79636 T291 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 79636 T291 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 79637 T291 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 79637 T291 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 79637 T291 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 79638 T291 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 79638 T291 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 79638 T291 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 79639 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 79642 T291 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4]   2> 79643 T291 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50700/solr
[junit4:junit4]   2> 79643 T291 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 79644 T291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 79645 T379 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1574409e name:ZooKeeperConnection Watcher:127.0.0.1:50700 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 79646 T291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 79648 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 79651 T291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 79653 T381 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f4e1672 name:ZooKeeperConnection Watcher:127.0.0.1:50700/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 79653 T291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 79662 T291 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4]   2> 80665 T291 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33227_
[junit4:junit4]   2> 80666 T291 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:33227_
[junit4:junit4]   2> 80668 T333 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 80668 T349 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4]   2> 80669 T365 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 80669 T313 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 80670 T313 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 80670 T320 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 80669 T365 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 80670 T320 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 80670 T381 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 80671 T349 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 80672 T333 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 80677 T382 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 80678 T382 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 80944 T314 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 80945 T314 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":"127.0.0.1:36518__collection1",
[junit4:junit4]   2>  "numShards":"3",
[junit4:junit4]   2>  "shard":"shard3",
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"active",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:36518_",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:36518"}
[junit4:junit4]   2> 80948 T314 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":null,
[junit4:junit4]   2>  "numShards":"3",
[junit4:junit4]   2>  "shard":null,
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"down",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:33227_",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:33227"}
[junit4:junit4]   2> 80948 T314 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4]   2> 80949 T314 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4]   2> 81016 T365 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 81016 T313 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 81016 T381 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 81016 T320 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 81016 T349 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 81016 T333 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 81679 T382 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372394491292/collection1
[junit4:junit4]   2> 81679 T382 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 81680 T382 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 81680 T382 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 81682 T382 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372394491292/collection1/'
[junit4:junit4]   2> 81682 T382 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372394491292/collection1/lib/README' to classloader
[junit4:junit4]   2> 81682 T382 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372394491292/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 81708 T382 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   2> 81746 T382 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 81748 T382 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 81752 T382 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4]   2> 82076 T382 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4]   2> 82077 T382 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4]   2> 82077 T382 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 82083 T382 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 82086 T382 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 82101 T382 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 82104 T382 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 82107 T382 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 82108 T382 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 82108 T382 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 82109 T382 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 82110 T382 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 82110 T382 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 82110 T382 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 82110 T382 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1372394491292/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty4/
[junit4:junit4]   2> 82111 T382 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@359ecd80
[junit4:junit4]   2> 82111 T382 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 82112 T382 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty4
[junit4:junit4]   2> 82112 T382 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty4/index/
[junit4:junit4]   2> 82112 T382 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 82113 T382 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty4/index
[junit4:junit4]   2> 82197 T382 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty4/index,segFN=segments_1,generation=1}
[junit4:junit4]   2> 82198 T382 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 82200 T382 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 82200 T382 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 82201 T382 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 82201 T382 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 82202 T382 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 82202 T382 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 82202 T382 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 82203 T382 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 82203 T382 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 82205 T382 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 82208 T382 oass.SolrIndexSearcher.<init> Opening Searcher@68d31619 main
[junit4:junit4]   2> 82208 T382 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 82209 T382 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 82213 T383 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@68d31619 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 82215 T382 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 82216 T382 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:33227 collection:collection1 shard:shard1
[junit4:junit4]   2> 82219 T382 oasc.ZkController.register We are http://127.0.0.1:33227/collection1/ and leader is http://127.0.0.1:35920/collection1/
[junit4:junit4]   2> 82219 T382 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:33227
[junit4:junit4]   2> 82219 T382 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 82219 T382 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C29 name=collection1 org.apache.solr.core.SolrCore@6b2f5733 url=http://127.0.0.1:33227/collection1 node=127.0.0.1:33227_ C29_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:33227_, base_url=http://127.0.0.1:33227}
[junit4:junit4]   2> 82222 T384 C29 P33227 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 82223 T382 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 82223 T384 C29 P33227 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 82223 T384 C29 P33227 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 82224 T384 C29 P33227 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 82224 T291 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 82225 T291 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 82225 T384 C29 P33227 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 82225 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 82232 T329 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:33227__collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4]   2> 82307 T291 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4]   2> 82309 T291 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58397
[junit4:junit4]   2> 82310 T291 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 82310 T291 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 82311 T291 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372394494037
[junit4:junit4]   2> 82311 T291 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372394494037/solr.xml
[junit4:junit4]   2> 82311 T291 oasc.CoreContainer.<init> New CoreContainer 1369984726
[junit4:junit4]   2> 82312 T291 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372394494037/'
[junit4:junit4]   2> 82312 T291 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372394494037/'
[junit4:junit4]   2> 82366 T291 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 82366 T291 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 82367 T291 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 82367 T291 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 82367 T291 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 82368 T291 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 82368 T291 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 82368 T291 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 82369 T291 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 82369 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 82373 T291 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4]   2> 82374 T291 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50700/solr
[junit4:junit4]   2> 82374 T291 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 82375 T291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 82377 T396 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@362024a6 name:ZooKeeperConnection Watcher:127.0.0.1:50700 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 82377 T291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 82379 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 82382 T291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 82383 T398 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@57a165ca name:ZooKeeperConnection Watcher:127.0.0.1:50700/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 82384 T291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 82387 T291 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4]   2> 82523 T314 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 82524 T314 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":"127.0.0.1:33227__collection1",
[junit4:junit4]   2>  "numShards":"3",
[junit4:junit4]   2>  "shard":"shard1",
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"recovering",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:33227_",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:33227"}
[junit4:junit4]   2> 82528 T320 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 82529 T313 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 82529 T398 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 82529 T381 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 82529 T333 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 82528 T349 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 82528 T365 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 83233 T329 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:33227__collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4]   2> 83234 T329 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:33227__collection1&state=recovering&nodeName=127.0.0.1:33227_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1002
[junit4:junit4]   2> 83390 T291 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58397_
[junit4:junit4]   2> 83391 T291 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58397_
[junit4:junit4]   2> 83394 T349 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 83394 T333 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 83394 T320 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4]   2> 83394 T381 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 83395 T365 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4]   2> 83395 T313 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4]   2> 83395 T320 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 83394 T398 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4]   2> 83395 T313 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 83395 T365 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 83397 T333 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4]   2> 83397 T349 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4]   2> 83399 T381 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4]   2> 83399 T398 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4]   2> 83402 T399 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 83403 T399 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 84033 T314 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 84034 T314 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":null,
[junit4:junit4]   2>  "numShards":"3",
[junit4:junit4]   2>  "shard":null,
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"down",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:58397_",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:58397"}
[junit4:junit4]   2> 84035 T314 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4]   2> 84035 T314 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4]   2> 84039 T365 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 84039 T313 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 84039 T398 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 84039 T381 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 84039 T320 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 84039 T333 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 84039 T349 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 84404 T399 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372394494037/collection1
[junit4:junit4]   2> 84404 T399 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 84405 T399 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 84405 T399 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 84407 T399 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372394494037/collection1/'
[junit4:junit4]   2> 84407 T399 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372394494037/collection1/lib/README' to classloader
[junit4:junit4]   2> 84408 T399 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372394494037/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 84435 T399 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   2> 84466 T399 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 84467 T399 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 84473 T399 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4]   2> 84833 T399 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4]   2> 84833 T399 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4]   2> 84834 T399 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 84840 T399 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 84843 T399 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 84860 T399 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 84863 T399 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 84866 T399 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 84867 T399 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 84868 T399 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 84868 T399 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 84869 T399 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 84869 T399 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 84869 T399 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 84870 T399 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1372394494037/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty5/
[junit4:junit4]   2> 84870 T399 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@359ecd80
[junit4:junit4]   2> 84870 T399 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 84871 T399 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty5
[junit4:junit4]   2> 84871 T399 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty5/index/
[junit4:junit4]   2> 84872 T399 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty5/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 84872 T399 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty5/index
[junit4:junit4]   2> 84877 T399 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty5/index,segFN=segments_1,generation=1}
[junit4:junit4]   2> 84877 T399 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 84879 T399 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 84879 T399 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 84880 T399 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 84881 T399 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 84881 T399 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 84881 T399 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 84882 T399 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 84882 T399 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 84883 T399 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 84884 T399 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 84888 T399 oass.SolrIndexSearcher.<init> Opening Searcher@51504155 main
[junit4:junit4]   2> 84888 T399 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 84888 T399 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 84893 T400 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@51504155 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 84896 T399 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 84896 T399 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58397 collection:collection1 shard:shard2
[junit4:junit4]   2> 84899 T399 oasc.ZkController.register We are http://127.0.0.1:58397/collection1/ and leader is http://127.0.0.1:40779/collection1/
[junit4:junit4]   2> 84899 T399 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58397
[junit4:junit4]   2> 84899 T399 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 84899 T399 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C30 name=collection1 org.apache.solr.core.SolrCore@3385f539 url=http://127.0.0.1:58397/collection1 node=127.0.0.1:58397_ C30_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:58397_, base_url=http://127.0.0.1:58397}
[junit4:junit4]   2> 84900 T401 C30 P58397 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 84900 T399 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 84900 T401 C30 P58397 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 84901 T401 C30 P58397 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 84903 T401 C30 P58397 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 84901 T291 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 84904 T291 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 84904 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 84904 T401 C30 P58397 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 84911 T343 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:58397__collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4]   2> 84987 T291 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4]   2> 84989 T291 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53404
[junit4:junit4]   2> 84989 T291 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 84990 T291 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 84990 T291 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372394496714
[junit4:junit4]   2> 84990 T291 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372394496714/solr.xml
[junit4:junit4]   2> 84991 T291 oasc.CoreContainer.<init> New CoreContainer 525049519
[junit4:junit4]   2> 84991 T291 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372394496714/'
[junit4:junit4]   2> 84992 T291 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372394496714/'
[junit4:junit4]   2> 85038 T291 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 85038 T291 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 85039 T291 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 85039 T291 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 85039 T291 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 85040 T291 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 85040 T291 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 85041 T291 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 85041 T291 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 85041 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 85044 T291 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4]   2> 85045 T291 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50700/solr
[junit4:junit4]   2> 85045 T291 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 85046 T291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 85048 T413 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@328bdd6b name:ZooKeeperConnection Watcher:127.0.0.1:50700 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 85048 T291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 85053 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 85057 T291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 85058 T415 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@24b9371e name:ZooKeeperConnection Watcher:127.0.0.1:50700/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 85058 T291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 85062 T291 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4]   2> ASYNC  NEW_CORE C31 name=collection1 org.apache.solr.core.SolrCore@6b2f5733 url=http://127.0.0.1:33227/collection1 node=127.0.0.1:33227_ C31_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:33227_, base_url=http://127.0.0.1:33227}
[junit4:junit4]   2> 85236 T384 C31 P33227 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:35920/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 85239 T384 C31 P33227 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&connTimeout=30000&socketTimeout=30000&retry=false
[junit4:junit4]   2> 85243 T384 C31 P33227 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:33227 START replicas=[http://127.0.0.1:35920/collection1/] nUpdates=100
[junit4:junit4]   2> 85245 T384 C31 P33227 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 85245 T384 C31 P33227 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 85246 T384 C31 P33227 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 85246 T384 C31 P33227 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 85246 T384 C31 P33227 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 85246 T384 C31 P33227 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:35920/collection1/. core=collection1
[junit4:junit4]   2> 85246 T384 C31 P33227 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C32 name=collection1 org.apache.solr.core.SolrCore@6e26a4ce url=http://127.0.0.1:35920/collection1 node=127.0.0.1:35920_ C32_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:35920_, base_url=http://127.0.0.1:35920, leader=true}
[junit4:junit4]   2> 85256 T326 C32 P35920 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4]   2> 85261 T327 C32 P35920 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 85264 T327 C32 P35920 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4]   2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty1/index,segFN=segments_1,generation=1}
[junit4:junit4]   2> 85264 T327 C32 P35920 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 85265 T327 C32 P35920 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4]   2> 85265 T327 C32 P35920 oass.SolrIndexSearcher.<init> Opening Searcher@3d2656d3 realtime
[junit4:junit4]   2> 85266 T327 C32 P35920 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 85266 T327 C32 P35920 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 7
[junit4:junit4]   2> 85267 T384 C31 P33227 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 85267 T384 C31 P33227 oascsi.HttpClientUtil.createClient Creating new http client, config:connTimeout=5000&socketTimeout=20000&allowCompression=false&maxConnections=10000&maxConnectionsPerHost=10000
[junit4:junit4]   2> 85272 T384 C31 P33227 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 85274 T328 C32 P35920 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 85275 T328 C32 P35920 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=2
[junit4:junit4]   2> 85276 T384 C31 P33227 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 85276 T384 C31 P33227 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 85276 T384 C31 P33227 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 85276 T384 C31 P33227 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 85277 T384 C31 P33227 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 85545 T314 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 85546 T314 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":"127.0.0.1:58397__collection1",
[junit4:junit4]   2>  "numShards":"3",
[junit4:junit4]   2>  "shard":"shard2",
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"recovering",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:58397_",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:58397"}
[junit4:junit4]   2> 85549 T314 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":"127.0.0.1:33227__collection1",
[junit4:junit4]   2>  "numShards":"3",
[junit4:junit4]   2>  "shard":"shard1",
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"active",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:33227_",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:33227"}
[junit4:junit4]   2> 85636 T365 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 85636 T398 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 85636 T381 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 85636 T313 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 85636 T349 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 85636 T333 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 85636 T415 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 85636 T320 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 85911 T343 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:58397__collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4]   2> 85912 T343 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:58397__collection1&state=recovering&nodeName=127.0.0.1:58397_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1001
[junit4:junit4]   2> 86065 T291 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53404_
[junit4:junit4]   2> 86066 T291 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53404_
[junit4:junit4]   2> 86068 T349 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 86069 T398 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 86069 T381 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 86068 T333 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 6)
[junit4:junit4]   2> 86069 T365 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4]   2> 86069 T313 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4]   2> 86070 T313 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 86069 T415 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4]   2> 86071 T415 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 86070 T365 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 86070 T320 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4]   2> 86072 T349 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4]   2> 86072 T320 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 86073 T333 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4]   2> 86073 T381 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4]   2> 86074 T398 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4]   2> 86077 T417 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 86077 T417 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 87145 T314 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 87146 T314 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":null,
[junit4:junit4]   2>  "numShards":"3",
[junit4:junit4]   2>  "shard":null,
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"down",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:53404_",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:53404"}
[junit4:junit4]   2> 87146 T314 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4]   2> 87146 T314 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard3
[junit4:junit4]   2> 87150 T365 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 87150 T333 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 87151 T313 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 87151 T398 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 87151 T381 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 87150 T415 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 87150 T349 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 87150 T320 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> ASYNC  NEW_CORE C33 name=collection1 org.apache.solr.core.SolrCore@3385f539 url=http://127.0.0.1:58397/collection1 node=127.0.0.1:58397_ C33_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:58397_, base_url=http://127.0.0.1:58397}
[junit4:junit4]   2> 87913 T401 C33 P58397 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:40779/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 87914 T401 C33 P58397 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:58397 START replicas=[http://127.0.0.1:40779/collection1/] nUpdates=100
[junit4:junit4]   2> 87915 T401 C33 P58397 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 87915 T401 C33 P58397 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 87915 T401 C33 P58397 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 87915 T401 C33 P58397 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 87916 T401 C33 P58397 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 87916 T401 C33 P58397 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:40779/collection1/. core=collection1
[junit4:junit4]   2> 87917 T401 C33 P58397 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C34 name=collection1 org.apache.solr.core.SolrCore@395b1bc2 url=http://127.0.0.1:40779/collection1 node=127.0.0.1:40779_ C34_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:40779_, base_url=http://127.0.0.1:40779, leader=true}
[junit4:junit4]   2> 87923 T342 C34 P40779 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4]   2> 87924 T344 C34 P40779 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 87926 T344 C34 P40779 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4]   2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty2/index,segFN=segments_1,generation=1}
[junit4:junit4]   2> 87927 T344 C34 P40779 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 87927 T344 C34 P40779 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4]   2> 87928 T344 C34 P40779 oass.SolrIndexSearcher.<init> Opening Searcher@6ebbd7d realtime
[junit4:junit4]   2> 87928 T344 C34 P40779 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 87928 T344 C34 P40779 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 4
[junit4:junit4]   2> 87930 T401 C33 P58397 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 87930 T401 C33 P58397 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 87932 T345 C34 P40779 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 87932 T345 C34 P40779 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4:junit4]   2> 87933 T401 C33 P58397 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 87933 T401 C33 P58397 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 87933 T401 C33 P58397 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 87934 T401 C33 P58397 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 87935 T401 C33 P58397 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 88079 T417 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372394496714/collection1
[junit4:junit4]   2> 88080 T417 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 88081 T417 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 88081 T417 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 88082 T417 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372394496714/collection1/'
[junit4:junit4]   2> 88082 T417 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372394496714/collection1/lib/README' to classloader
[junit4:junit4]   2> 88083 T417 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372394496714/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 88108 T417 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   2> 88138 T417 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 88140 T417 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 88144 T417 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4]   2> 88513 T417 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4]   2> 88513 T417 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4]   2> 88514 T417 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 88520 T417 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 88522 T417 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 88540 T417 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 88545 T417 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 88549 T417 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 88550 T417 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 88551 T417 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 88551 T417 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 88552 T417 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 88553 T417 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 88553 T417 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 88553 T417 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1372394496714/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty6/
[junit4:junit4]   2> 88554 T417 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@359ecd80
[junit4:junit4]   2> 88555 T417 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 88555 T417 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty6
[junit4:junit4]   2> 88556 T417 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty6/index/
[junit4:junit4]   2> 88556 T417 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty6/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 88557 T417 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty6/index
[junit4:junit4]   2> 88560 T417 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty6/index,segFN=segments_1,generation=1}
[junit4:junit4]   2> 88560 T417 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 88564 T417 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 88565 T417 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 88565 T417 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 88566 T417 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 88568 T417 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 88568 T417 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 88572 T417 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 88573 T417 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 88573 T417 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 88576 T417 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 88581 T417 oass.SolrIndexSearcher.<init> Opening Searcher@14ddf6a1 main
[junit4:junit4]   2> 88582 T417 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 88582 T417 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 88588 T419 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@14ddf6a1 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 88591 T417 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 88592 T417 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53404 collection:collection1 shard:shard3
[junit4:junit4]   2> 88596 T417 oasc.ZkController.register We are http://127.0.0.1:53404/collection1/ and leader is http://127.0.0.1:36518/collection1/
[junit4:junit4]   2> 88597 T417 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53404
[junit4:junit4]   2> 88597 T417 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 88598 T417 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C35 name=collection1 org.apache.solr.core.SolrCore@6633a290 url=http://127.0.0.1:53404/collection1 node=127.0.0.1:53404_ C35_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:53404_, base_url=http://127.0.0.1:53404}
[junit4:junit4]   2> 88598 T420 C35 P53404 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 88599 T417 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 88599 T420 C35 P53404 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 88600 T420 C35 P53404 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 88600 T420 C35 P53404 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 88602 T420 C35 P53404 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 88610 T360 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:53404__collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4]   2> 88611 T291 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 88612 T291 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 88612 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 88657 T314 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 88658 T314 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":"127.0.0.1:58397__collection1",
[junit4:junit4]   2>  "numShards":"3",
[junit4:junit4]   2>  "shard":"shard2",
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"active",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:58397_",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:58397"}
[junit4:junit4]   2> 88662 T314 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":"127.0.0.1:53404__collection1",
[junit4:junit4]   2>  "numShards":"3",
[junit4:junit4]   2>  "shard":"shard3",
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"recovering",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:53404_",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:53404"}
[junit4:junit4]   2> 88668 T365 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 88668 T398 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 88669 T333 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 88669 T320 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 88669 T381 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 88669 T349 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 88668 T313 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 88669 T415 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 88737 T291 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4]   2> 88740 T291 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:56322
[junit4:junit4]   2> 88741 T291 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 88742 T291 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 88742 T291 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1372394500424
[junit4:junit4]   2> 88743 T291 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1372394500424/solr.xml
[junit4:junit4]   2> 88743 T291 oasc.CoreContainer.<init> New CoreContainer 255008226
[junit4:junit4]   2> 88744 T291 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1372394500424/'
[junit4:junit4]   2> 88745 T291 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1372394500424/'
[junit4:junit4]   2> 88809 T291 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 88810 T291 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 88811 T291 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 88811 T291 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 88812 T291 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 88812 T291 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 88813 T291 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 88813 T291 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 88814 T291 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 88814 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 88819 T291 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4]   2> 88820 T291 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50700/solr
[junit4:junit4]   2> 88821 T291 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 88834 T291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 88835 T432 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d029f4 name:ZooKeeperConnection Watcher:127.0.0.1:50700 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 88835 T291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 88838 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 88846 T291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 88848 T434 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@34ab5770 name:ZooKeeperConnection Watcher:127.0.0.1:50700/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 88848 T291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 88852 T291 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4]   2> 89611 T360 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:53404__collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4]   2> 89612 T360 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:53404__collection1&state=recovering&nodeName=127.0.0.1:53404_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1002
[junit4:junit4]   2> 89856 T291 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56322_
[junit4:junit4]   2> 89857 T291 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:56322_
[junit4:junit4]   2> 89859 T349 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 89859 T333 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 89860 T398 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 89860 T381 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 7)
[junit4:junit4]   2> 89861 T415 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4]   2> 89862 T434 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4]   2> 89861 T320 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4]   2> 89862 T320 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 8)
[junit4:junit4]   2> 89861 T365 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4]   2> 89862 T415 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 8)
[junit4:junit4]   2> 89861 T313 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4]   2> 89863 T313 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 8)
[junit4:junit4]   2> 89863 T349 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4]   2> 89863 T365 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 8)
[junit4:junit4]   2> 89864 T398 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4]   2> 89865 T381 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4]   2> 89866 T333 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4]   2> 89870 T435 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 89870 T435 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 90178 T314 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 90179 T314 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":null,
[junit4:junit4]   2>  "numShards":"3",
[junit4:junit4]   2>  "shard":null,
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"down",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:56322_",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:56322"}
[junit4:junit4]   2> 90180 T314 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4]   2> 90180 T314 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4]   2> 90246 T365 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4]   2> 90246 T349 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4]   2> 90246 T434 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4]   2> 90246 T415 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4]   2> 90246 T398 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4]   2> 90246 T381 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4]   2> 90246 T320 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4]   2> 90246 T333 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4]   2> 90246 T313 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4]   2> 90871 T435 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1372394500424/collection1
[junit4:junit4]   2> 90872 T435 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 90873 T435 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 90873 T435 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 90875 T435 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1372394500424/collection1/'
[junit4:junit4]   2> 90876 T435 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1372394500424/collection1/lib/README' to classloader
[junit4:junit4]   2> 90876 T435 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1372394500424/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 90914 T435 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4]   2> 90949 T435 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 90951 T435 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4]   2> 90956 T435 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4]   2> 91276 T435 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4]   2> 91276 T435 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4]   2> 91277 T435 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 91283 T435 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 91285 T435 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 91304 T435 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 91309 T435 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 91313 T435 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 91314 T435 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 91315 T435 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 91315 T435 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 91316 T435 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 91316 T435 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4]   2> 91317 T435 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 91317 T435 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1372394500424/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty7/
[junit4:junit4]   2> 91318 T435 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@359ecd80
[junit4:junit4]   2> 91318 T435 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 91319 T435 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty7
[junit4:junit4]   2> 91319 T435 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty7/index/
[junit4:junit4]   2> 91320 T435 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty7/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 91320 T435 oasc.CachingDirectoryFactory.get return new directory for /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty7/index
[junit4:junit4]   2> 91323 T435 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4]   2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty7/index,segFN=segments_1,generation=1}
[junit4:junit4]   2> 91323 T435 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 91325 T435 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 91326 T435 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 91326 T435 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 91327 T435 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 91327 T435 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 91327 T435 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 91328 T435 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 91328 T435 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 91329 T435 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 91330 T435 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 91333 T435 oass.SolrIndexSearcher.<init> Opening Searcher@6be05ef2 main
[junit4:junit4]   2> 91334 T435 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 91334 T435 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 91339 T436 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6be05ef2 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 91341 T435 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 91341 T435 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:56322 collection:collection1 shard:shard1
[junit4:junit4]   2> 91344 T435 oasc.ZkController.register We are http://127.0.0.1:56322/collection1/ and leader is http://127.0.0.1:35920/collection1/
[junit4:junit4]   2> 91344 T435 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:56322
[junit4:junit4]   2> 91345 T435 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 91345 T435 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C36 name=collection1 org.apache.solr.core.SolrCore@7e7d611f url=http://127.0.0.1:56322/collection1 node=127.0.0.1:56322_ C36_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:56322_, base_url=http://127.0.0.1:56322}
[junit4:junit4]   2> 91345 T437 C36 P56322 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 91346 T437 C36 P56322 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 91346 T435 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 91346 T437 C36 P56322 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 91346 T437 C36 P56322 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 91347 T291 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1
[junit4:junit4]   2> 91347 T437 C36 P56322 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 91347 T291 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 91348 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 91354 T328 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:56322__collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4]   2> 91420 T291 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4]   2> 91423 T291 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53681
[junit4:junit4]   2> 91423 T291 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 91424 T291 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 91424 T291 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty8-1372394503158
[junit4:junit4]   2> 91424 T291 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty8-1372394503158/solr.xml
[junit4:junit4]   2> 91425 T291 oasc.CoreContainer.<init> New CoreContainer 1045788216
[junit4:junit4]   2> 91425 T291 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty8-1372394503158/'
[junit4:junit4]   2> 91425 T291 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty8-1372394503158/'
[junit4:junit4]   2> 91466 T291 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 91466 T291 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 91466 T291 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 91467 T291 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 91467 T291 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 91468 T291 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 91468 T291 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 91468 T291 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 91469 T291 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 91469 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 91472 T291 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4]   2> 91473 T291 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:50700/solr
[junit4:junit4]   2> 91473 T291 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 91474 T291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 91476 T449 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@663ffd14 name:ZooKeeperConnection Watcher:127.0.0.1:50700 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 91476 T291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 91478 T291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 91481 T291 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 91482 T451 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19f67d34 name:ZooKeeperConnection Watcher:127.0.0.1:50700/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 91483 T291 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 91486 T291 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4]   2> ASYNC  NEW_CORE C37 name=collection1 org.apache.solr.core.SolrCore@6633a290 url=http://127.0.0.1:53404/collection1 node=127.0.0.1:53404_ C37_STATE=coll:collection1 core:collection1 props:{shard=shard3, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:53404_, base_url=http://127.0.0.1:53404}
[junit4:junit4]   2> 91613 T420 C37 P53404 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:36518/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 91613 T420 C37 P53404 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:53404 START replicas=[http://127.0.0.1:36518/collection1/] nUpdates=100
[junit4:junit4]   2> 91614 T420 C37 P53404 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 91614 T420 C37 P53404 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 91615 T420 C37 P53404 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 91615 T420 C37 P53404 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 91615 T420 C37 P53404 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 91617 T420 C37 P53404 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:36518/collection1/. core=collection1
[junit4:junit4]   2> 91617 T420 C37 P53404 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C38 name=collection1 org.apache.solr.core.SolrCore@3d6bc07a url=http://127.0.0.1:36518/collection1 node=127.0.0.1:36518_ C38_STATE=coll:collection1 core:collection1 props:{shard=shard3, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:36518_, base_url=http://127.0.0.1:36518, leader=true}
[junit4:junit4]   2> 91620 T360 C38 P36518 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4]   2> 91621 T361 C38 P36518 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 91624 T361 C38 P36518 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4]   2> commit{dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1372394478567/jetty3/index,segFN=segments_1,generation=1}
[junit4:junit4]   2> 91625 T361 C38 P36518 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4]   2> 91625 T361 C38 P36518 oasu.DirectUpdateHandler2.commit No uncommitted changes. Skipping IW.commit.
[junit4:junit4]   2> 91625 T361 C38 P36518 oass.SolrIndexSearcher.<init> Opening Searcher@794f47c realtime
[junit4:junit4]   2> 91626 T361 C38 P36518 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 91626 T361 C38 P36518 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 5
[junit4:junit4]   2> 91627 T420 C37 P53404 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 91627 T420 C37 P53404 oash.SnapPuller.<init>  No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4]   2> 91630 T358 C38 P36518 oash.ReplicationHandler.inform Commits will be reserved for  10000
[junit4:junit4]   2> 91630 T358 C38 P36518 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4]   2> 91631 T420 C37 P53404 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4]   2> 91631 T420 C37 P53404 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4]   2> 91631 T420 C37 P53404 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 91631 T420 C37 P53404 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 91633 T420 C37 P53404 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4]   2> 91754 T314 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4]   2> 91755 T314 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":"127.0.0.1:56322__collection1",
[junit4:junit4]   2>  "numShards":"3",
[junit4:junit4]   2>  "shard":"shard1",
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"recovering",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:56322_",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:56322"}
[junit4:junit4]   2> 91760 T314 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2>  "operation":"state",
[junit4:junit4]   2>  "core_node_name":"127.0.0.1:53404__collection1",
[junit4:junit4]   2>  "numShards":"3",
[junit4:junit4]   2>  "shard":"shard3",
[junit4:junit4]   2>  "roles":null,
[junit4:junit4]   2>  "state":"active",
[junit4:junit4]   2>  "shard_state":"active",
[junit4:junit4]   2>  "core":"collection1",
[junit4:junit4]   2>  "collection":"collection1",
[junit4:junit4]   2>  "shard_range":null,
[junit4:junit4]   2>  "node_name":"127.0.0.1:53404_",
[junit4:junit4]   2>  "base_url":"http://127.0.0.1:53404"}
[junit4:junit4]   2> 91766 T320 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4]   2> 91766 T381 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4]   2> 91767 T434 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4]   2> 91767 T451 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4]   2> 91766 T349 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4]   2> 91766 T398 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4]   2> 91766 T313 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4]   2> 91766 T415 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4]   2> 91766 T333 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4]   2> 91766 T365 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 8)
[junit4:junit4]   2> 92354 T328 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:56322__collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4]   2> 92355 T328 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:56322__collection1&state=recovering&nodeName=127.0.0.1:56322_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1001
[junit4:junit4]   2> 92489 T291 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53681_
[junit4:junit4]   2> 92490 T291 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53681_
[junit4:junit4]   2> 92492 T349 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 8)
[junit4:junit4]   2

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

hronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
[junit4:junit4]   2>        at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:399)
[junit4:junit4]   2>        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:957)
[junit4:junit4]   2>        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:917)
[junit4:junit4]   2>        at java.lang.Thread.run(Thread.java:662)
[junit4:junit4]   2>  74) Thread[id=575, name=qtp134495191-575 Selector0, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4:junit4]   2>        at sun.nio.ch.EPollArrayWrapper.interrupt(Native Method)
[junit4:junit4]   2>        at sun.nio.ch.EPollArrayWrapper.interrupt(EPollArrayWrapper.java:256)
[junit4:junit4]   2>        at sun.nio.ch.EPollSelectorImpl.wakeup(EPollSelectorImpl.java:175)
[junit4:junit4]   2>        at java.nio.channels.spi.AbstractSelector$1.interrupt(AbstractSelector.java:193)
[junit4:junit4]   2>        at java.nio.channels.spi.AbstractSelector.begin(AbstractSelector.java:198)
[junit4:junit4]   2>        at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:64)
[junit4:junit4]   2>        at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:69)
[junit4:junit4]   2>        at sun.nio.ch.SelectorImpl.selectNow(SelectorImpl.java:88)
[junit4:junit4]   2>        at org.eclipse.jetty.io.nio.SelectorManager$SelectSet.doSelect(SelectorManager.java:536)
[junit4:junit4]   2>        at org.eclipse.jetty.io.nio.SelectorManager$1.run(SelectorManager.java:290)
[junit4:junit4]   2>        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
[junit4:junit4]   2>        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4:junit4]   2>        at java.lang.Thread.run(Thread.java:662)
[junit4:junit4]   2>  75) Thread[id=590, name=Thread-242, state=WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4:junit4]   2>        at java.lang.Object.wait(Native Method)
[junit4:junit4]   2>        at java.lang.Object.wait(Object.java:485)
[junit4:junit4]   2>        at org.apache.solr.core.CloserThread.run(CoreContainer.java:1304)
[junit4:junit4]   2>  76) Thread[id=568, name=Thread-216-SendThread(localhost.localdomain:50700), state=TIMED_WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4:junit4]   2>        at java.lang.Thread.sleep(Native Method)
[junit4:junit4]   2>        at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:86)
[junit4:junit4]   2>        at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:937)
[junit4:junit4]   2>        at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:993)
[junit4:junit4]   2>  77) Thread[id=390, name=qtp947242391-390 Acceptor1 SelectChannelConnector@127.0.0.1:58397, state=BLOCKED, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4:junit4]   2>        at org.eclipse.jetty.server.nio.SelectChannelConnector.getConnection(SelectChannelConnector.java:160)
[junit4:junit4]   2>        at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:934)
[junit4:junit4]   2>        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
[junit4:junit4]   2>        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4:junit4]   2>        at java.lang.Thread.run(Thread.java:662)
[junit4:junit4]   2>  78) Thread[id=426, name=qtp533686947-426 Acceptor1 SelectChannelConnector@127.0.0.1:56322, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4:junit4]   2>        at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:956)
[junit4:junit4]   2>        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
[junit4:junit4]   2>        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4:junit4]   2>        at java.lang.Thread.run(Thread.java:662)
[junit4:junit4]   2>  79) Thread[id=619, name=TEST-ChaosMonkeySafeLeaderTest.testDistribSearch-seed#[D1FD32D6913264B5]-SendThread(localhost.localdomain:50700), state=TIMED_WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4:junit4]   2>        at java.lang.Thread.sleep(Native Method)
[junit4:junit4]   2>        at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:86)
[junit4:junit4]   2>        at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:937)
[junit4:junit4]   2>        at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:993)
[junit4:junit4]   2>  80) Thread[id=585, name=Thread-216-SendThread(localhost.localdomain:50700), state=TIMED_WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4:junit4]   2>        at java.lang.Thread.sleep(Native Method)
[junit4:junit4]   2>        at org.apache.zookeeper.client.StaticHostProvider.next(StaticHostProvider.java:86)
[junit4:junit4]   2>        at org.apache.zookeeper.ClientCnxn$SendThread.startConnect(ClientCnxn.java:937)
[junit4:junit4]   2>        at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:993)
[junit4:junit4]   2>  81) Thread[id=496, name=qtp1282230271-496 Acceptor0 SelectChannelConnector@127.0.0.1:50263, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4:junit4]   2>        at org.eclipse.jetty.server.AbstractConnector$Acceptor.run(AbstractConnector.java:956)
[junit4:junit4]   2>        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:608)
[junit4:junit4]   2>        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:543)
[junit4:junit4]   2>        at java.lang.Thread.run(Thread.java:662)
[junit4:junit4]   2> 7292561 T585 oaz.ClientCnxn$SendThread.run WARN Session 0x13f8915dbea0020 for server null, unexpected error, closing socket connection and attempting reconnect java.net.ConnectException: Connection refused
[junit4:junit4]   2> at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit4:junit4]   2> at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:599)
[junit4:junit4]   2> at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:350)
[junit4:junit4]   2> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
[junit4:junit4]   2>
[junit4:junit4]   2> 7292591 T623 oaz.ClientCnxn$SendThread.run WARN Session 0x13f8915dbea0025 for server null, unexpected error, closing socket connection and attempting reconnect java.net.ConnectException: Connection refused
[junit4:junit4]   2> at sun.nio.ch.SocketChannelImpl.checkConnect(Native Method)
[junit4:junit4]   2> at sun.nio.ch.SocketChannelImpl.finishConnect(SocketChannelImpl.java:599)
[junit4:junit4]   2> at org.apache.zookeeper.ClientCnxnSocketNIO.doTransport(ClientCnxnSocketNIO.java:350)
[junit4:junit4]   2> at org.apache.zookeeper.ClientCnxn$SendThread.run(ClientCnxn.java:1068)
[junit4:junit4]   2>
[junit4:junit4]   2> NOTE: test params are: codec=FastCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=FAST, chunkSize=256), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=FAST, chunkSize=256)), sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=iw, timezone=Antarctica/McMurdo
[junit4:junit4]   2> NOTE: Linux 3.2.0-48-generic amd64/Sun Microsystems Inc. 1.6.0_45 (64-bit)/cpus=8,threads=101,free=76460024,total=165478400
[junit4:junit4]   2> NOTE: All tests run in this JVM: [TestMultiCoreConfBootstrap, TestZkChroot, HighlighterConfigTest, TestLMJelinekMercerSimilarityFactory, TestCoreDiscovery, SpellCheckComponentTest, TestSolrJ, ConvertedLegacyTest, IndexBasedSpellCheckerTest, TestComponentsName, TestBinaryField, SimplePostToolTest, SolrRequestParserTest, TestCSVResponseWriter, ShardRoutingCustomTest, TestLazyCores, TestMergePolicyConfig, TestNumberUtils, XmlUpdateRequestHandlerTest, URLClassifyProcessorTest, QueryResultKeyTest, ChaosMonkeySafeLeaderTest]
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=ChaosMonkeySafeLeaderTest -Dtests.seed=D1FD32D6913264B5 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=iw -Dtests.timezone=Antarctica/McMurdo -Dtests.file.encoding=ISO-8859-1
[junit4:junit4] ERROR   0.00s J1 | ChaosMonkeySafeLeaderTest (suite) <<<
[junit4:junit4]    > Throwable #1: java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
[junit4:junit4]    > at __randomizedtesting.SeedInfo.seed([D1FD32D6913264B5]:0)
[junit4:junit4] Completed on J1 in 7226.00s, 1 test, 2 errors <<< FAILURES!

[...truncated 164 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:392: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:372: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:181: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:437: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1248: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:892: There were test failures: 299 suites, 1290 tests, 1 suite-level error, 1 error, 148 ignored (6 assumptions)

Total time: 140 minutes 37 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.6.0_45 -XX:+UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure




---------------------------------------------------------------------
To unsubscribe, e-mail: [hidden email]
For additional commands, e-mail: [hidden email]