You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/06/22 22:05:01 UTC
[JENKINS] Lucene-Solr-4.x-Windows (32bit/jdk1.6.0_45) - Build #
2920 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/2920/
Java: 32bit/jdk1.6.0_45 -server -XX:+UseParallelGC
2 tests failed.
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([C175E917F746EF2C]:0)
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([C175E917F746EF2C]:0)
Build Log:
[...truncated 8976 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
[junit4:junit4] 2> 488564 T1017 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /kd/kp
[junit4:junit4] 2> 488570 T1017 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-ChaosMonkeySafeLeaderTest-1371923201635
[junit4:junit4] 2> 488572 T1017 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 488614 T1018 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 488653 T1017 oasc.ZkTestServer.run start zk server on port:57969
[junit4:junit4] 2> 488654 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 488661 T1024 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1710777 name:ZooKeeperConnection Watcher:127.0.0.1:57969 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 488661 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 488661 T1017 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 488672 T1019 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13f6cfebe930000, likely client has closed socket
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4:junit4] 2>
[junit4:junit4] 2> 488672 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 488681 T1026 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@126ac06 name:ZooKeeperConnection Watcher:127.0.0.1:57969/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 488681 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 488681 T1017 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 488690 T1017 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 488695 T1017 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 488700 T1017 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 488704 T1017 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 488705 T1017 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 488714 T1017 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 488715 T1017 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 488721 T1017 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 488721 T1017 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 488726 T1017 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 488727 T1017 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 488732 T1017 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 488732 T1017 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 488737 T1017 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 488737 T1017 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 488742 T1017 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 488743 T1017 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 488748 T1017 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 488749 T1017 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 488753 T1017 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 488754 T1017 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 488760 T1019 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13f6cfebe930001, likely client has closed socket
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4:junit4] 2>
[junit4:junit4] 2> 489132 T1017 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 489136 T1017 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57976
[junit4:junit4] 2> 489136 T1017 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 489136 T1017 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 489137 T1017 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1371923201824
[junit4:junit4] 2> 489137 T1017 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1371923201824\solr.xml
[junit4:junit4] 2> 489138 T1017 oasc.CoreContainer.<init> New CoreContainer 25638510
[junit4:junit4] 2> 489139 T1017 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1371923201824\'
[junit4:junit4] 2> 489139 T1017 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1371923201824\'
[junit4:junit4] 2> 489269 T1017 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 489269 T1017 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 489269 T1017 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 489269 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 489270 T1017 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 489270 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 489272 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 489272 T1017 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 489272 T1017 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 489273 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 489286 T1017 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 489286 T1017 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57969/solr
[junit4:junit4] 2> 489287 T1017 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 489291 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 489308 T1037 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c5d21e name:ZooKeeperConnection Watcher:127.0.0.1:57969 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 489309 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 489314 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 489322 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 489326 T1039 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@45013 name:ZooKeeperConnection Watcher:127.0.0.1:57969/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 489326 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 489330 T1017 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 489338 T1017 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 489344 T1017 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 489348 T1017 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57976_kd%2Fkp
[junit4:junit4] 2> 489351 T1017 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57976_kd%2Fkp
[junit4:junit4] 2> 489357 T1017 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 489368 T1017 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 489372 T1017 oasc.Overseer.start Overseer (id=89910358945497091-127.0.0.1:57976_kd%2Fkp-n_0000000000) starting
[junit4:junit4] 2> 489381 T1017 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 489388 T1041 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 489389 T1017 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 489393 T1017 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 489397 T1017 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 489402 T1040 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 489407 T1042 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 489407 T1042 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 490602 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 490603 T1040 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[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:57976_kd%2Fkp",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:57976/kd/kp"}
[junit4:junit4] 2> 490603 T1040 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 490603 T1040 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 490612 T1039 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> 491004 T1042 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1371923201824\collection1
[junit4:junit4] 2> 491004 T1042 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 491006 T1042 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 491006 T1042 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 491009 T1042 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1371923201824\collection1\'
[junit4:junit4] 2> 491011 T1042 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1371923201824/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 491012 T1042 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1371923201824/collection1/lib/README' to classloader
[junit4:junit4] 2> 491066 T1042 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 491120 T1042 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 491122 T1042 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 491126 T1042 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 491707 T1042 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 491707 T1042 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 491709 T1042 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 491718 T1042 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 491722 T1042 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 491741 T1042 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 491746 T1042 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 491751 T1042 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 491752 T1042 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 491752 T1042 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 491752 T1042 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 491754 T1042 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 491754 T1042 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 491754 T1042 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 491782 T1042 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1371923201824\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634/control/data\
[junit4:junit4] 2> 491782 T1042 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2d95b3
[junit4:junit4] 2> 491783 T1042 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 491784 T1042 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\control\data
[junit4:junit4] 2> 491784 T1042 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634/control/data\index/
[junit4:junit4] 2> 491786 T1042 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\control\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 491786 T1042 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\control\data\index
[junit4:junit4] 2> 491796 T1042 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\control\data\index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 491796 T1042 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 491798 T1042 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 491798 T1042 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 491799 T1042 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 491800 T1042 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 491800 T1042 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 491800 T1042 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 491800 T1042 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 491800 T1042 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 491801 T1042 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 491807 T1042 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 491817 T1042 oass.SolrIndexSearcher.<init> Opening Searcher@4a9d91 main
[junit4:junit4] 2> 491818 T1042 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 491819 T1042 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 491823 T1043 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4a9d91 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 491823 T1042 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 491824 T1042 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57976/kd/kp collection:control_collection shard:shard1
[junit4:junit4] 2> 491825 T1042 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 491837 T1042 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 491841 T1042 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 491842 T1042 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 491842 T1042 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57976/kd/kp/collection1/
[junit4:junit4] 2> 491842 T1042 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 491842 T1042 oasc.SyncStrategy.syncToMe http://127.0.0.1:57976/kd/kp/collection1/ has no replicas
[junit4:junit4] 2> 491842 T1042 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57976/kd/kp/collection1/
[junit4:junit4] 2> 491842 T1042 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 493014 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 493030 T1039 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> 493068 T1042 oasc.ZkController.register We are http://127.0.0.1:57976/kd/kp/collection1/ and leader is http://127.0.0.1:57976/kd/kp/collection1/
[junit4:junit4] 2> 493068 T1042 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57976/kd/kp
[junit4:junit4] 2> 493068 T1042 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 493068 T1042 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 493069 T1042 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 493071 T1042 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 493072 T1017 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 493072 T1017 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 493072 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 493079 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 493082 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 493085 T1046 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1e25a69 name:ZooKeeperConnection Watcher:127.0.0.1:57969/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 493086 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 493088 T1017 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 493092 T1017 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 493466 T1017 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 493469 T1017 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57988
[junit4:junit4] 2> 493470 T1017 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 493470 T1017 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 493471 T1017 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1371923206156
[junit4:junit4] 2> 493471 T1017 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1371923206156\solr.xml
[junit4:junit4] 2> 493471 T1017 oasc.CoreContainer.<init> New CoreContainer 16444199
[junit4:junit4] 2> 493472 T1017 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1371923206156\'
[junit4:junit4] 2> 493472 T1017 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1371923206156\'
[junit4:junit4] 2> 493560 T1017 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 493561 T1017 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 493561 T1017 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 493561 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 493561 T1017 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 493561 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 493561 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 493562 T1017 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 493562 T1017 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 493563 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 493570 T1017 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 493571 T1017 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57969/solr
[junit4:junit4] 2> 493571 T1017 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 493572 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 493585 T1057 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@386a0f name:ZooKeeperConnection Watcher:127.0.0.1:57969 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 493585 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 493589 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 493589 T1019 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13f6cfebe930005, likely client has closed socket
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4:junit4] 2>
[junit4:junit4] 2> 493595 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 493599 T1059 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d48ad name:ZooKeeperConnection Watcher:127.0.0.1:57969/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 493599 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 493607 T1017 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 494236 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 494237 T1040 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[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:57976_kd%2Fkp",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:57976/kd/kp"}
[junit4:junit4] 2> 494245 T1039 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> 494246 T1059 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> 494245 T1046 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> 494408 T1017 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57988_kd%2Fkp
[junit4:junit4] 2> 494411 T1017 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57988_kd%2Fkp
[junit4:junit4] 2> 494415 T1039 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 494415 T1059 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 494415 T1046 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 494415 T1046 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> 494419 T1039 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 494419 T1059 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 494427 T1060 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 494427 T1060 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 495412 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 495414 T1040 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[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:57988_kd%2Fkp",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:57988/kd/kp"}
[junit4:junit4] 2> 495414 T1040 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 3
[junit4:junit4] 2> 495414 T1040 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 495423 T1046 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> 495423 T1059 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> 495423 T1039 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> 495929 T1060 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1371923206156\collection1
[junit4:junit4] 2> 495929 T1060 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 495929 T1060 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 495929 T1060 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 495932 T1060 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1371923206156\collection1\'
[junit4:junit4] 2> 495934 T1060 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1371923206156/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 495934 T1060 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1371923206156/collection1/lib/README' to classloader
[junit4:junit4] 2> 495976 T1060 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 496025 T1060 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 496026 T1060 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 496030 T1060 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 496587 T1060 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 496587 T1060 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 496588 T1060 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 496596 T1060 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 496599 T1060 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 496616 T1060 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 496620 T1060 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 496624 T1060 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 496626 T1060 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 496626 T1060 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 496627 T1060 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 496627 T1060 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 496628 T1060 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 496628 T1060 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 496629 T1060 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1371923206156\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634/jetty1\
[junit4:junit4] 2> 496629 T1060 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2d95b3
[junit4:junit4] 2> 496629 T1060 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 496629 T1060 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty1
[junit4:junit4] 2> 496630 T1060 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634/jetty1\index/
[junit4:junit4] 2> 496631 T1060 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty1\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 496631 T1060 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty1\index
[junit4:junit4] 2> 496639 T1060 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty1\index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 496640 T1060 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 496643 T1060 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 496643 T1060 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 496644 T1060 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 496645 T1060 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 496645 T1060 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 496645 T1060 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 496646 T1060 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 496647 T1060 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 496648 T1060 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 496655 T1060 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 496662 T1060 oass.SolrIndexSearcher.<init> Opening Searcher@1729e5a main
[junit4:junit4] 2> 496663 T1060 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 496663 T1060 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 496668 T1060 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 496668 T1060 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57988/kd/kp collection:collection1 shard:shard1
[junit4:junit4] 2> 496669 T1060 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 496673 T1061 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1729e5a main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 496680 T1060 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 496684 T1060 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 496685 T1060 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 496685 T1060 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57988/kd/kp/collection1/
[junit4:junit4] 2> 496685 T1060 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 496685 T1060 oasc.SyncStrategy.syncToMe http://127.0.0.1:57988/kd/kp/collection1/ has no replicas
[junit4:junit4] 2> 496685 T1060 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57988/kd/kp/collection1/
[junit4:junit4] 2> 496685 T1060 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 497586 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 497603 T1046 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> 497603 T1059 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> 497603 T1039 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> 497607 T1060 oasc.ZkController.register We are http://127.0.0.1:57988/kd/kp/collection1/ and leader is http://127.0.0.1:57988/kd/kp/collection1/
[junit4:junit4] 2> 497607 T1060 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57988/kd/kp
[junit4:junit4] 2> 497608 T1060 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 497608 T1060 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 497609 T1060 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 497612 T1060 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 497614 T1017 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 497614 T1017 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 497614 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 497991 T1017 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 497994 T1017 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57997
[junit4:junit4] 2> 497995 T1017 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 497996 T1017 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 497996 T1017 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1371923210685
[junit4:junit4] 2> 497996 T1017 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1371923210685\solr.xml
[junit4:junit4] 2> 497996 T1017 oasc.CoreContainer.<init> New CoreContainer 18262374
[junit4:junit4] 2> 497997 T1017 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1371923210685\'
[junit4:junit4] 2> 497998 T1017 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1371923210685\'
[junit4:junit4] 2> 498097 T1017 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 498098 T1017 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 498098 T1017 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 498099 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 498099 T1017 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 498099 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 498099 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 498099 T1017 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 498099 T1017 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 498100 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 498106 T1017 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 498107 T1017 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57969/solr
[junit4:junit4] 2> 498107 T1017 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 498108 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 498124 T1073 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@12ca045 name:ZooKeeperConnection Watcher:127.0.0.1:57969 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 498125 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 498152 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 498152 T1019 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13f6cfebe930007, likely client has closed socket
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:662)
[junit4:junit4] 2>
[junit4:junit4] 2> 498158 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 498160 T1075 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@12c542d name:ZooKeeperConnection Watcher:127.0.0.1:57969/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 498160 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 498167 T1017 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 498692 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 498694 T1040 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[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:57988_kd%2Fkp",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:57988/kd/kp"}
[junit4:junit4] 2> 498701 T1046 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> 498701 T1075 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> 498701 T1059 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> 498702 T1039 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> 498888 T1017 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57997_kd%2Fkp
[junit4:junit4] 2> 498890 T1017 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57997_kd%2Fkp
[junit4:junit4] 2> 498893 T1039 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> 498893 T1059 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> 498894 T1046 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 498894 T1046 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> 498895 T1075 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 498895 T1075 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> 498897 T1039 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 498898 T1059 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 498904 T1076 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 498904 T1076 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 499785 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 499787 T1040 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[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:57997_kd%2Fkp",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:57997/kd/kp"}
[junit4:junit4] 2> 499787 T1040 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 499787 T1040 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 499797 T1046 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> 499798 T1075 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> 499798 T1039 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> 499799 T1059 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> 500341 T1076 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1371923210685\collection1
[junit4:junit4] 2> 500341 T1076 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 500342 T1076 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 500342 T1076 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 500347 T1076 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1371923210685\collection1\'
[junit4:junit4] 2> 500348 T1076 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1371923210685/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 500349 T1076 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1371923210685/collection1/lib/README' to classloader
[junit4:junit4] 2> 500394 T1076 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 500442 T1076 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 500444 T1076 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 500447 T1076 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 500958 T1076 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 500959 T1076 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 500959 T1076 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 500969 T1076 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 500972 T1076 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 500988 T1076 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 500993 T1076 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 500997 T1076 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 500999 T1076 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 500999 T1076 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 500999 T1076 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 501000 T1076 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 501000 T1076 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 501000 T1076 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 501001 T1076 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1371923210685\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634/jetty2\
[junit4:junit4] 2> 501001 T1076 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2d95b3
[junit4:junit4] 2> 501001 T1076 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 501002 T1076 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty2
[junit4:junit4] 2> 501002 T1076 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634/jetty2\index/
[junit4:junit4] 2> 501003 T1076 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty2\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 501004 T1076 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty2\index
[junit4:junit4] 2> 501011 T1076 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty2\index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 501012 T1076 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 501014 T1076 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 501014 T1076 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 501014 T1076 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 501015 T1076 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 501016 T1076 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 501016 T1076 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 501016 T1076 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 501016 T1076 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 501016 T1076 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 501022 T1076 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 501030 T1076 oass.SolrIndexSearcher.<init> Opening Searcher@7318cf main
[junit4:junit4] 2> 501033 T1076 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 501033 T1076 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 501040 T1077 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7318cf main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 501042 T1076 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 501042 T1076 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57997/kd/kp collection:collection1 shard:shard2
[junit4:junit4] 2> 501043 T1076 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 501056 T1076 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 501061 T1076 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 501061 T1076 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 501062 T1076 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57997/kd/kp/collection1/
[junit4:junit4] 2> 501062 T1076 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 501062 T1076 oasc.SyncStrategy.syncToMe http://127.0.0.1:57997/kd/kp/collection1/ has no replicas
[junit4:junit4] 2> 501063 T1076 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57997/kd/kp/collection1/
[junit4:junit4] 2> 501063 T1076 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 501962 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 501974 T1046 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> 501974 T1059 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> 501974 T1039 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> 501974 T1075 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> 501985 T1076 oasc.ZkController.register We are http://127.0.0.1:57997/kd/kp/collection1/ and leader is http://127.0.0.1:57997/kd/kp/collection1/
[junit4:junit4] 2> 501985 T1076 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57997/kd/kp
[junit4:junit4] 2> 501985 T1076 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 501985 T1076 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 501985 T1076 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 501988 T1076 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 501989 T1017 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 501989 T1017 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 501989 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 502300 T1017 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 502302 T1017 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58006
[junit4:junit4] 2> 502304 T1017 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 502304 T1017 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 502304 T1017 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1371923215058
[junit4:junit4] 2> 502304 T1017 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1371923215058\solr.xml
[junit4:junit4] 2> 502304 T1017 oasc.CoreContainer.<init> New CoreContainer 11920763
[junit4:junit4] 2> 502305 T1017 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1371923215058\'
[junit4:junit4] 2> 502305 T1017 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1371923215058\'
[junit4:junit4] 2> 502374 T1017 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 502374 T1017 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 502375 T1017 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 502375 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 502375 T1017 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 502375 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 502375 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 502375 T1017 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 502376 T1017 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 502376 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 502382 T1017 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 502382 T1017 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57969/solr
[junit4:junit4] 2> 502382 T1017 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 502384 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 502395 T1089 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ab85c1 name:ZooKeeperConnection Watcher:127.0.0.1:57969 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 502396 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 502398 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 502403 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 502406 T1091 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f28052 name:ZooKeeperConnection Watcher:127.0.0.1:57969/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 502406 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 502412 T1017 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 502979 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 502980 T1040 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[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:57997_kd%2Fkp",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:57997/kd/kp"}
[junit4:junit4] 2> 502986 T1046 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> 502987 T1091 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> 502987 T1075 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> 502988 T1059 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> 502988 T1039 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> 503062 T1017 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58006_kd%2Fkp
[junit4:junit4] 2> 503063 T1017 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58006_kd%2Fkp
[junit4:junit4] 2> 503067 T1091 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> 503068 T1039 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> 503068 T1059 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> 503068 T1046 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 503068 T1046 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> 503069 T1075 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 503070 T1075 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> 503072 T1091 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 503072 T1059 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 503073 T1039 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 503080 T1092 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 503081 T1092 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 503963 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 503963 T1040 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"4",
[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:58006_kd%2Fkp",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58006/kd/kp"}
[junit4:junit4] 2> 503963 T1040 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 503963 T1040 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard3
[junit4:junit4] 2> 503972 T1046 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> 503972 T1075 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> 503973 T1039 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> 503973 T1059 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> 503972 T1091 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> 504374 T1092 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1371923215058\collection1
[junit4:junit4] 2> 504374 T1092 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 504374 T1092 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 504375 T1092 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 504378 T1092 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1371923215058\collection1\'
[junit4:junit4] 2> 504380 T1092 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1371923215058/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 504380 T1092 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1371923215058/collection1/lib/README' to classloader
[junit4:junit4] 2> 504432 T1092 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 504473 T1092 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 504475 T1092 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 504480 T1092 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 504936 T1092 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 504936 T1092 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 504937 T1092 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 504945 T1092 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 504951 T1092 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 504967 T1092 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 504972 T1092 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 504976 T1092 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 504978 T1092 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 504978 T1092 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 504978 T1092 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 504979 T1092 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 504979 T1092 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 504980 T1092 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 504980 T1092 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1371923215058\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634/jetty3\
[junit4:junit4] 2> 504980 T1092 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2d95b3
[junit4:junit4] 2> 504980 T1092 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 504981 T1092 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty3
[junit4:junit4] 2> 504982 T1092 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634/jetty3\index/
[junit4:junit4] 2> 504982 T1092 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty3\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 504982 T1092 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty3\index
[junit4:junit4] 2> 504991 T1092 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty3\index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 504991 T1092 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 504993 T1092 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 504994 T1092 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 504994 T1092 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 504994 T1092 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 504995 T1092 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 504995 T1092 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 504995 T1092 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 504996 T1092 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 504996 T1092 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 505001 T1092 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 505008 T1092 oass.SolrIndexSearcher.<init> Opening Searcher@10d77d main
[junit4:junit4] 2> 505009 T1092 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 505009 T1092 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 505013 T1093 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@10d77d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 505014 T1092 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 505014 T1092 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58006/kd/kp collection:collection1 shard:shard3
[junit4:junit4] 2> 505015 T1092 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4:junit4] 2> 505023 T1092 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 505027 T1092 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 505027 T1092 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 505027 T1092 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58006/kd/kp/collection1/
[junit4:junit4] 2> 505027 T1092 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 505027 T1092 oasc.SyncStrategy.syncToMe http://127.0.0.1:58006/kd/kp/collection1/ has no replicas
[junit4:junit4] 2> 505027 T1092 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58006/kd/kp/collection1/
[junit4:junit4] 2> 505027 T1092 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4:junit4] 2> 505918 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 505944 T1091 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> 505945 T1075 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> 505945 T1039 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> 505944 T1046 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> 505945 T1059 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> 505953 T1092 oasc.ZkController.register We are http://127.0.0.1:58006/kd/kp/collection1/ and leader is http://127.0.0.1:58006/kd/kp/collection1/
[junit4:junit4] 2> 505953 T1092 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58006/kd/kp
[junit4:junit4] 2> 505953 T1092 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 505953 T1092 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 505954 T1092 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 505956 T1092 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 505957 T1017 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 505958 T1017 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 505958 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 506290 T1017 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 506292 T1017 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58015
[junit4:junit4] 2> 506293 T1017 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 506294 T1017 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 506294 T1017 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1371923219028
[junit4:junit4] 2> 506295 T1017 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1371923219028\solr.xml
[junit4:junit4] 2> 506295 T1017 oasc.CoreContainer.<init> New CoreContainer 21747053
[junit4:junit4] 2> 506295 T1017 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1371923219028\'
[junit4:junit4] 2> 506296 T1017 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1371923219028\'
[junit4:junit4] 2> 506403 T1017 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 506404 T1017 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 506404 T1017 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 506404 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 506404 T1017 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 506404 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 506405 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 506406 T1017 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 506406 T1017 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 506406 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 506415 T1017 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 506416 T1017 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57969/solr
[junit4:junit4] 2> 506416 T1017 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 506418 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 506429 T1105 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@661bf4 name:ZooKeeperConnection Watcher:127.0.0.1:57969 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 506430 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 506433 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 506440 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 506445 T1107 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1945f01 name:ZooKeeperConnection Watcher:127.0.0.1:57969/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 506445 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 506453 T1017 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 506923 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 506923 T1040 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"4",
[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:58006_kd%2Fkp",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58006/kd/kp"}
[junit4:junit4] 2> 506932 T1046 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> 506932 T1039 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> 506932 T1107 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> 506932 T1075 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> 506932 T1091 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> 506932 T1059 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> 507103 T1017 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58015_kd%2Fkp
[junit4:junit4] 2> 507105 T1017 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58015_kd%2Fkp
[junit4:junit4] 2> 507108 T1091 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> 507108 T1039 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> 507109 T1107 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> 507109 T1059 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> 507110 T1046 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 507110 T1046 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> 507111 T1075 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 507111 T1075 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> 507114 T1039 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 507114 T1091 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 507114 T1107 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 507115 T1059 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 507122 T1108 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 507122 T1108 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 507908 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 507909 T1040 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"5",
[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:58015_kd%2Fkp",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58015/kd/kp"}
[junit4:junit4] 2> 507910 T1040 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 507910 T1040 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 507919 T1046 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> 507920 T1075 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> 507920 T1039 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> 507921 T1107 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> 507919 T1091 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> 507921 T1059 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> 508417 T1108 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1371923219028\collection1
[junit4:junit4] 2> 508417 T1108 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 508417 T1108 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 508417 T1108 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 508419 T1108 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1371923219028\collection1\'
[junit4:junit4] 2> 508420 T1108 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1371923219028/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 508421 T1108 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1371923219028/collection1/lib/README' to classloader
[junit4:junit4] 2> 508455 T1108 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 508497 T1108 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 508499 T1108 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 508502 T1108 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 508937 T1108 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 508937 T1108 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 508938 T1108 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 508945 T1108 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 508946 T1108 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 508959 T1108 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 508962 T1108 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 508965 T1108 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 508966 T1108 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 508966 T1108 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 508967 T1108 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 508968 T1108 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 508968 T1108 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 508968 T1108 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 508969 T1108 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1371923219028\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634/jetty4\
[junit4:junit4] 2> 508969 T1108 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2d95b3
[junit4:junit4] 2> 508969 T1108 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 508970 T1108 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty4
[junit4:junit4] 2> 508970 T1108 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634/jetty4\index/
[junit4:junit4] 2> 508971 T1108 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty4\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 508971 T1108 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty4\index
[junit4:junit4] 2> 508978 T1108 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty4\index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 508978 T1108 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 508979 T1108 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 508980 T1108 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 508980 T1108 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 508981 T1108 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 508981 T1108 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 508981 T1108 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 508981 T1108 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 508982 T1108 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 508982 T1108 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 508987 T1108 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 508992 T1108 oass.SolrIndexSearcher.<init> Opening Searcher@1926419 main
[junit4:junit4] 2> 508994 T1108 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 508994 T1108 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 508998 T1109 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1926419 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 508999 T1108 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 508999 T1108 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58015/kd/kp collection:collection1 shard:shard1
[junit4:junit4] 2> 509002 T1108 oasc.ZkController.register We are http://127.0.0.1:58015/kd/kp/collection1/ and leader is http://127.0.0.1:57988/kd/kp/collection1/
[junit4:junit4] 2> 509003 T1108 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58015/kd/kp
[junit4:junit4] 2> 509003 T1108 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 509003 T1108 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C294 name=collection1 org.apache.solr.core.SolrCore@abd879 url=http://127.0.0.1:58015/kd/kp/collection1 node=127.0.0.1:58015_kd%2Fkp C294_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:58015_kd%2Fkp, base_url=http://127.0.0.1:58015/kd/kp}
[junit4:junit4] 2> 509003 T1110 C294 P58015 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 509003 T1110 C294 P58015 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 509004 T1110 C294 P58015 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 509004 T1110 C294 P58015 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 509004 T1108 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 509006 T1110 C294 P58015 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 509006 T1017 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 509007 T1017 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 509007 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 509012 T1055 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 509260 T1017 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 509261 T1017 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58025
[junit4:junit4] 2> 509262 T1017 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 509262 T1017 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 509262 T1017 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1371923222076
[junit4:junit4] 2> 509263 T1017 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1371923222076\solr.xml
[junit4:junit4] 2> 509263 T1017 oasc.CoreContainer.<init> New CoreContainer 26477688
[junit4:junit4] 2> 509264 T1017 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1371923222076\'
[junit4:junit4] 2> 509264 T1017 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1371923222076\'
[junit4:junit4] 2> 509331 T1017 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 509331 T1017 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 509331 T1017 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 509331 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 509331 T1017 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 509332 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 509332 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 509332 T1017 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 509332 T1017 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 509332 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 509337 T1017 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 509338 T1017 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57969/solr
[junit4:junit4] 2> 509338 T1017 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 509339 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 509349 T1122 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b8520 name:ZooKeeperConnection Watcher:127.0.0.1:57969 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 509350 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 509352 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 509356 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 509358 T1124 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@67345 name:ZooKeeperConnection Watcher:127.0.0.1:57969/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 509358 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 509362 T1017 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 509751 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 509752 T1040 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"5",
[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:58015_kd%2Fkp",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58015/kd/kp"}
[junit4:junit4] 2> 509760 T1075 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> 509760 T1039 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> 509760 T1124 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> 509761 T1046 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> 509761 T1091 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> 509763 T1059 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> 509763 T1107 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> 509947 T1017 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58025_kd%2Fkp
[junit4:junit4] 2> 509949 T1017 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58025_kd%2Fkp
[junit4:junit4] 2> 509953 T1124 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 509953 T1039 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> 509953 T1091 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> 509953 T1046 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 509953 T1107 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> 509954 T1059 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> 509953 T1124 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> 509953 T1046 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> 509955 T1075 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 509955 T1075 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> 509959 T1039 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 509959 T1091 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 509959 T1107 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 509960 T1059 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 509966 T1125 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 509966 T1125 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 510175 T1055 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 510175 T1055 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=5&state=recovering&nodeName=127.0.0.1:58015_kd%252Fkp&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1163
[junit4:junit4] 2> 510640 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 510640 T1040 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"6",
[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:58025_kd%2Fkp",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58025/kd/kp"}
[junit4:junit4] 2> 510640 T1040 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 510641 T1040 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 510647 T1124 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> 510647 T1075 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> 510647 T1046 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> 510648 T1039 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> 510648 T1091 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> 510648 T1107 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> 510648 T1059 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> 511131 T1125 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1371923222076\collection1
[junit4:junit4] 2> 511131 T1125 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 511132 T1125 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 511132 T1125 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 511134 T1125 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1371923222076\collection1\'
[junit4:junit4] 2> 511135 T1125 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1371923222076/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 511136 T1125 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1371923222076/collection1/lib/README' to classloader
[junit4:junit4] 2> 511185 T1125 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 511239 T1125 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 511240 T1125 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 511244 T1125 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> ASYNC NEW_CORE C295 name=collection1 org.apache.solr.core.SolrCore@abd879 url=http://127.0.0.1:58015/kd/kp/collection1 node=127.0.0.1:58015_kd%2Fkp C295_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:58015_kd%2Fkp, base_url=http://127.0.0.1:58015/kd/kp}
[junit4:junit4] 2> 511337 T1110 C295 P58015 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:57988/kd/kp/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 511337 T1110 C295 P58015 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:58015/kd/kp START replicas=[http://127.0.0.1:57988/kd/kp/collection1/] nUpdates=100
[junit4:junit4] 2> 511338 T1110 C295 P58015 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 511338 T1110 C295 P58015 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 511338 T1110 C295 P58015 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 511339 T1110 C295 P58015 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 511339 T1110 C295 P58015 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 511339 T1110 C295 P58015 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:57988/kd/kp/collection1/. core=collection1
[junit4:junit4] 2> 511339 T1110 C295 P58015 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C296 name=collection1 org.apache.solr.core.SolrCore@19882ec url=http://127.0.0.1:57988/kd/kp/collection1 node=127.0.0.1:57988_kd%2Fkp C296_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:57988_kd%2Fkp, base_url=http://127.0.0.1:57988/kd/kp, leader=true}
[junit4:junit4] 2> 511352 T1054 C296 P57988 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 511357 T1055 C296 P57988 oasc.SolrCore.execute [collection1] webapp=/kd/kp path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 511360 T1054 C296 P57988 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty1\index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 511361 T1054 C296 P57988 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 511368 T1054 C296 P57988 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty1\index,segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty1\index,segFN=segments_2,generation=2}
[junit4:junit4] 2> 511369 T1054 C296 P57988 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 511371 T1054 C296 P57988 oass.SolrIndexSearcher.<init> Opening Searcher@fe19b5 realtime
[junit4:junit4] 2> 511371 T1054 C296 P57988 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 511371 T1054 C296 P57988 oasup.LogUpdateProcessor.finish [collection1] webapp=/kd/kp path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 19
[junit4:junit4] 2> 511373 T1110 C295 P58015 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 511373 T1110 C295 P58015 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 511375 T1054 C296 P57988 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 511375 T1054 C296 P57988 oasc.SolrCore.execute [collection1] webapp=/kd/kp path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4:junit4] 2> 511375 T1110 C295 P58015 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 511376 T1110 C295 P58015 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 511376 T1110 C295 P58015 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 511380 T1051 C296 P57988 oasc.SolrCore.execute [collection1] webapp=/kd/kp path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=2
[junit4:junit4] 2> 511380 T1110 C295 P58015 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 511382 T1110 C295 P58015 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty4\index.20130622134704444
[junit4:junit4] 2> 511383 T1110 C295 P58015 oash.SnapPuller.fetchLatestIndex Starting download to org.apache.lucene.store.SimpleFSDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty4\index.20130622134704444 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1b9c3be fullCopy=false
[junit4:junit4] 2> 511390 T1053 C296 P57988 oasc.SolrCore.execute [collection1] webapp=/kd/kp path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 511396 T1110 C295 P58015 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 511399 T1110 C295 P58015 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 511400 T1110 C295 P58015 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 511403 T1110 C295 P58015 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty4\index,segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty4\index,segFN=segments_2,generation=2}
[junit4:junit4] 2> 511403 T1110 C295 P58015 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 511403 T1110 C295 P58015 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 511404 T1110 C295 P58015 oass.SolrIndexSearcher.<init> Opening Searcher@1ad21cb main
[junit4:junit4] 2> 511405 T1109 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1ad21cb main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 511405 T1110 C295 P58015 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty4\index.20130622134704444 [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty4\index.20130622134704444;done=true>>]
[junit4:junit4] 2> 511405 T1110 C295 P58015 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty4\index.20130622134704444
[junit4:junit4] 2> 511405 T1110 C295 P58015 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty4\index.20130622134704444
[junit4:junit4] 2> 511406 T1110 C295 P58015 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 511406 T1110 C295 P58015 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 511407 T1110 C295 P58015 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 511407 T1110 C295 P58015 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 511409 T1110 C295 P58015 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 511529 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 511530 T1040 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"5",
[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:58015_kd%2Fkp",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58015/kd/kp"}
[junit4:junit4] 2> 511541 T1075 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> 511541 T1039 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> 511541 T1091 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> 511542 T1107 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> 511542 T1046 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> 511541 T1124 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> 511542 T1059 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> 511717 T1125 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 511718 T1125 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 511718 T1125 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 511725 T1125 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 511728 T1125 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 511742 T1125 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 511753 T1125 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 511758 T1125 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 511760 T1125 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 511760 T1125 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 511760 T1125 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 511761 T1125 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 511761 T1125 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 511762 T1125 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 511762 T1125 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1371923222076\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634/jetty5\
[junit4:junit4] 2> 511762 T1125 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2d95b3
[junit4:junit4] 2> 511762 T1125 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 511764 T1125 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty5
[junit4:junit4] 2> 511765 T1125 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634/jetty5\index/
[junit4:junit4] 2> 511766 T1125 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty5\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 511766 T1125 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty5\index
[junit4:junit4] 2> 511772 T1125 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty5\index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 511772 T1125 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 511774 T1125 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 511774 T1125 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 511774 T1125 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 511775 T1125 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 511775 T1125 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 511775 T1125 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 511778 T1125 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 511779 T1125 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 511779 T1125 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 511783 T1125 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 511789 T1125 oass.SolrIndexSearcher.<init> Opening Searcher@666358 main
[junit4:junit4] 2> 511790 T1125 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 511790 T1125 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 511793 T1128 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@666358 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 511795 T1125 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 511795 T1125 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58025/kd/kp collection:collection1 shard:shard2
[junit4:junit4] 2> 511799 T1125 oasc.ZkController.register We are http://127.0.0.1:58025/kd/kp/collection1/ and leader is http://127.0.0.1:57997/kd/kp/collection1/
[junit4:junit4] 2> 511799 T1125 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58025/kd/kp
[junit4:junit4] 2> 511799 T1125 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 511799 T1125 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C297 name=collection1 org.apache.solr.core.SolrCore@10b287f url=http://127.0.0.1:58025/kd/kp/collection1 node=127.0.0.1:58025_kd%2Fkp C297_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:58025_kd%2Fkp, base_url=http://127.0.0.1:58025/kd/kp}
[junit4:junit4] 2> 511801 T1129 C297 P58025 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 511802 T1129 C297 P58025 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 511802 T1129 C297 P58025 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 511802 T1129 C297 P58025 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 511802 T1125 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 511803 T1129 C297 P58025 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 511804 T1017 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 511804 T1017 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 511804 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 511815 T1065 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 6, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 512077 T1017 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 512079 T1017 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58038
[junit4:junit4] 2> 512080 T1017 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 512080 T1017 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 512080 T1017 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1371923224877
[junit4:junit4] 2> 512080 T1017 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1371923224877\solr.xml
[junit4:junit4] 2> 512081 T1017 oasc.CoreContainer.<init> New CoreContainer 24544592
[junit4:junit4] 2> 512081 T1017 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1371923224877\'
[junit4:junit4] 2> 512081 T1017 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1371923224877\'
[junit4:junit4] 2> 512142 T1017 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 512142 T1017 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 512142 T1017 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 512142 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 512142 T1017 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 512143 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 512143 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 512143 T1017 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 512143 T1017 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 512143 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 512148 T1017 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 512149 T1017 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57969/solr
[junit4:junit4] 2> 512149 T1017 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 512150 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 512160 T1141 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d816cc name:ZooKeeperConnection Watcher:127.0.0.1:57969 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 512160 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 512163 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 512170 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 512172 T1143 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11ab5dc name:ZooKeeperConnection Watcher:127.0.0.1:57969/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 512173 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 512179 T1017 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 512421 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 512422 T1040 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"6",
[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:58025_kd%2Fkp",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58025/kd/kp"}
[junit4:junit4] 2> 512429 T1143 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> 512429 T1124 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> 512429 T1046 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> 512429 T1059 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> 512429 T1075 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> 512429 T1107 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> 512429 T1091 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> 512429 T1039 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> 512763 T1017 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58038_kd%2Fkp
[junit4:junit4] 2> 512767 T1017 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58038_kd%2Fkp
[junit4:junit4] 2> 512770 T1039 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> 512770 T1091 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> 512770 T1107 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> 512770 T1059 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> 512771 T1143 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 512771 T1143 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> 512772 T1124 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 512772 T1124 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> 512772 T1046 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 512772 T1046 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> 512773 T1075 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 512773 T1075 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> 512776 T1091 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 512777 T1107 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 512777 T1059 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 512777 T1039 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 512783 T1144 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 512783 T1144 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 512977 T1065 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 6, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 512977 T1065 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=6&state=recovering&nodeName=127.0.0.1:58025_kd%252Fkp&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1162
[junit4:junit4] 2> 513312 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 513313 T1040 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"7",
[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:58038_kd%2Fkp",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58038/kd/kp"}
[junit4:junit4] 2> 513313 T1040 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 513313 T1040 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard3
[junit4:junit4] 2> 513322 T1124 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> 513323 T1143 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> 513324 T1075 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> 513324 T1039 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> 513323 T1046 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> 513325 T1091 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> 513325 T1107 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> 513326 T1059 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> 513366 T1144 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1371923224877\collection1
[junit4:junit4] 2> 513366 T1144 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 513366 T1144 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 513366 T1144 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 513368 T1144 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1371923224877\collection1\'
[junit4:junit4] 2> 513369 T1144 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1371923224877/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 513370 T1144 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1371923224877/collection1/lib/README' to classloader
[junit4:junit4] 2> 513402 T1144 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 513440 T1144 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 513442 T1144 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 513446 T1144 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 513843 T1144 oass.ByteField.init WARN ByteField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 513843 T1144 oass.ShortField.init WARN ShortField is deprecated and will be removed in 5.0. You should use TrieIntField instead.
[junit4:junit4] 2> 513844 T1144 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 513850 T1144 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 513853 T1144 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 513866 T1144 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 513870 T1144 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 513873 T1144 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 513874 T1144 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 513874 T1144 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 513874 T1144 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 513875 T1144 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 513875 T1144 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 513875 T1144 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 513875 T1144 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1371923224877\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634/jetty6\
[junit4:junit4] 2> 513876 T1144 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2d95b3
[junit4:junit4] 2> 513876 T1144 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 513876 T1144 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty6
[junit4:junit4] 2> 513877 T1144 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634/jetty6\index/
[junit4:junit4] 2> 513877 T1144 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty6\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 513878 T1144 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty6\index
[junit4:junit4] 2> 513884 T1144 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty6\index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 513884 T1144 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 513885 T1144 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 513886 T1144 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 513886 T1144 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 513887 T1144 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 513887 T1144 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 513887 T1144 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 513887 T1144 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 513888 T1144 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 513888 T1144 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 513897 T1144 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 513904 T1144 oass.SolrIndexSearcher.<init> Opening Searcher@16848db main
[junit4:junit4] 2> 513905 T1144 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 513905 T1144 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 513908 T1145 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@16848db main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 513909 T1144 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 513909 T1144 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58038/kd/kp collection:collection1 shard:shard3
[junit4:junit4] 2> 513914 T1144 oasc.ZkController.register We are http://127.0.0.1:58038/kd/kp/collection1/ and leader is http://127.0.0.1:58006/kd/kp/collection1/
[junit4:junit4] 2> 513914 T1144 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58038/kd/kp
[junit4:junit4] 2> 513914 T1144 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 513914 T1144 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C298 name=collection1 org.apache.solr.core.SolrCore@1e76c2 url=http://127.0.0.1:58038/kd/kp/collection1 node=127.0.0.1:58038_kd%2Fkp C298_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:58038_kd%2Fkp, base_url=http://127.0.0.1:58038/kd/kp}
[junit4:junit4] 2> 513915 T1146 C298 P58038 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 513916 T1146 C298 P58038 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 513916 T1146 C298 P58038 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 513916 T1146 C298 P58038 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 513916 T1144 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 513917 T1146 C298 P58038 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 513918 T1017 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 513918 T1017 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 513919 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 513929 T1087 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 7, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> ASYNC NEW_CORE C299 name=collection1 org.apache.solr.core.SolrCore@10b287f url=http://127.0.0.1:58025/kd/kp/collection1 node=127.0.0.1:58025_kd%2Fkp C299_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:58025_kd%2Fkp, base_url=http://127.0.0.1:58025/kd/kp}
[junit4:junit4] 2> 514140 T1129 C299 P58025 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:57997/kd/kp/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 514141 T1129 C299 P58025 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:58025/kd/kp START replicas=[http://127.0.0.1:57997/kd/kp/collection1/] nUpdates=100
[junit4:junit4] 2> 514141 T1129 C299 P58025 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 514141 T1129 C299 P58025 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 514141 T1129 C299 P58025 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 514142 T1129 C299 P58025 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 514142 T1129 C299 P58025 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 514142 T1129 C299 P58025 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:57997/kd/kp/collection1/. core=collection1
[junit4:junit4] 2> 514142 T1129 C299 P58025 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C300 name=collection1 org.apache.solr.core.SolrCore@3929c7 url=http://127.0.0.1:57997/kd/kp/collection1 node=127.0.0.1:57997_kd%2Fkp C300_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:57997_kd%2Fkp, base_url=http://127.0.0.1:57997/kd/kp, leader=true}
[junit4:junit4] 2> 514167 T1069 C300 P57997 oasc.SolrCore.execute [collection1] webapp=/kd/kp path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 2> 514167 T1065 C300 P57997 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 514174 T1065 C300 P57997 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty2\index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 514174 T1065 C300 P57997 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 514186 T1065 C300 P57997 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty2\index,segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty2\index,segFN=segments_2,generation=2}
[junit4:junit4] 2> 514186 T1065 C300 P57997 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 514188 T1065 C300 P57997 oass.SolrIndexSearcher.<init> Opening Searcher@1a78115 realtime
[junit4:junit4] 2> 514188 T1065 C300 P57997 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 514189 T1065 C300 P57997 oasup.LogUpdateProcessor.finish [collection1] webapp=/kd/kp path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 22
[junit4:junit4] 2> 514190 T1129 C299 P58025 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 514190 T1129 C299 P58025 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 514193 T1068 C300 P57997 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 514194 T1068 C300 P57997 oasc.SolrCore.execute [collection1] webapp=/kd/kp path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> 514194 T1129 C299 P58025 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 514194 T1129 C299 P58025 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 514194 T1129 C299 P58025 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 514199 T1071 C300 P57997 oasc.SolrCore.execute [collection1] webapp=/kd/kp path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=2
[junit4:junit4] 2> 514199 T1129 C299 P58025 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 514201 T1129 C299 P58025 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty5\index.20130622134707263
[junit4:junit4] 2> 514202 T1129 C299 P58025 oash.SnapPuller.fetchLatestIndex Starting download to org.apache.lucene.store.SimpleFSDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty5\index.20130622134707263 lockFactory=org.apache.lucene.store.NativeFSLockFactory@b70cd6 fullCopy=false
[junit4:junit4] 2> 514204 T1067 C300 P57997 oasc.SolrCore.execute [collection1] webapp=/kd/kp path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 514205 T1129 C299 P58025 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 514208 T1129 C299 P58025 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 514208 T1129 C299 P58025 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 514211 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 514212 T1040 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"7",
[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:58038_kd%2Fkp",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58038/kd/kp"}
[junit4:junit4] 2> 514212 T1129 C299 P58025 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty5\index,segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty5\index,segFN=segments_2,generation=2}
[junit4:junit4] 2> 514213 T1129 C299 P58025 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 514213 T1129 C299 P58025 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 514214 T1129 C299 P58025 oass.SolrIndexSearcher.<init> Opening Searcher@6caa0d main
[junit4:junit4] 2> 514215 T1128 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6caa0d main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 514215 T1129 C299 P58025 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty5\index.20130622134707263 [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty5\index.20130622134707263;done=true>>]
[junit4:junit4] 2> 514216 T1129 C299 P58025 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty5\index.20130622134707263
[junit4:junit4] 2> 514216 T1129 C299 P58025 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371923201634\jetty5\index.20130622134707263
[junit4:junit4] 2> 514216 T1129 C299 P58025 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 514216 T1129 C299 P58025 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 514216 T1129 C299 P58025 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 514216 T1129 C299 P58025 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 514219 T1129 C299 P58025 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 514223 T1040 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"6",
[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:58025_kd%2Fkp",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58025/kd/kp"}
[junit4:junit4] 2> 514224 T1017 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 514226 T1017 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:58051
[junit4:junit4] 2> 514227 T1017 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 514227 T1017 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 514227 T1017 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1371923226989
[junit4:junit4] 2> 514228 T1017 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1371923226989\solr.xml
[junit4:junit4] 2> 514228 T1017 oasc.CoreContainer.<init> New CoreContainer 21383952
[junit4:junit4] 2> 514228 T1017 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1371923226989\'
[junit4:junit4] 2> 514228 T1017 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1371923226989\'
[junit4:junit4] 2> 514230 T1124 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> 514230 T1046 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> 514231 T1143 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> 514232 T1075 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> 514232 T1039 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> 514232 T1091 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> 514232 T1107 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> 514232 T1059 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> 514295 T1017 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 514295 T1017 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 514295 T1017 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 514295 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 514295 T1017 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 514295 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 514296 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 514296 T1017 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 514296 T1017 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 514296 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 514301 T1017 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 514302 T1017 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57969/solr
[junit4:junit4] 2> 514302 T1017 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 514304 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 514305 T1160 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1ab6b5e name:ZooKeeperConnection Watcher:127.0.0.1:57969 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 514306 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 514308 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 514312 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 514314 T1162 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10030d0 name:ZooKeeperConnection Watcher:127.0.0.1:57969/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 514314 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 514320 T1017 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 514510 T1087 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 7, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 514510 T1087 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=7&state=recovering&nodeName=127.0.0.1:58038_kd%252Fkp&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=581
[junit4:junit4] 2> 514942 T1017 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58051_kd%2Fkp
[junit4:junit4] 2> 514946 T1017 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58051_kd%2Fkp
[junit4:junit4] 2> 514949 T1107 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> 514950 T1039 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> 514949 T1091 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> 514951 T1059 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> 514952 T1124 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 514952 T1124 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> 514952 T1046 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 514952 T1075 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 514952 T1075 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> 514952 T1143 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 514953 T1143 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> 514952 T1162 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 514952 T1046 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> 514955 T1107 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 514955 T1039 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 514955 T1091 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 514956 T1059 oascc.ZkStateReader$3.process Updating live nodes... (8)
[junit4:junit4] 2> 514963 T1163 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 514963 T1163 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 515180 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 515180 T1040 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"8",
[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:58051_kd%2Fkp",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58051/kd/kp"}
[junit4:junit4] 2> 515180 T1040 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 515181 T1040 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 515187 T1124 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> 515188 T1046 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> 515188 T1143 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> 515188 T1162 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> 515188 T1075 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> 515189 T1039 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> 515189 T1091 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> 515190 T1059 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> 515190 T1107 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> 515604 T1163 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1371923226989\collection1
[junit4:junit4] 2> 515604 T1163 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 515605 T1163 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:juni
[...truncated too long message...]
unit4] 2> at java.lang.Object.wait(Native Method)
[junit4:junit4] 2> at java.util.TimerThread.mainLoop(Timer.java:509)
[junit4:junit4] 2> at java.util.TimerThread.run(Timer.java:462)
[junit4:junit4] 2> 56) Thread[id=1081, name=qtp30112183-1081 Acceptor0 SelectChannelConnector@127.0.0.1:58006, 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> 57) Thread[id=1064, name=qtp10742182-1064 Selector0, state=RUNNABLE, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4:junit4] 2> at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(Native Method)
[junit4:junit4] 2> at sun.nio.ch.WindowsSelectorImpl$SubSelector.poll(WindowsSelectorImpl.java:273)
[junit4:junit4] 2> at sun.nio.ch.WindowsSelectorImpl$SubSelector.access$400(WindowsSelectorImpl.java:255)
[junit4:junit4] 2> at sun.nio.ch.WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:136)
[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> 58) Thread[id=1274, name=commitScheduler-788-thread-1, state=WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4:junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4:junit4] 2> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
[junit4:junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)
[junit4:junit4] 2> at java.util.concurrent.DelayQueue.take(DelayQueue.java:160)
[junit4:junit4] 2> at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:609)
[junit4:junit4] 2> at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:602)
[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> 59) Thread[id=1384, name=qtp28932082-1384 Acceptor0 SelectChannelConnector@127.0.0.1:58038, 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> 60) Thread[id=1079, name=HashSessionScavenger-28, state=TIMED_WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4:junit4] 2> at java.lang.Object.wait(Native Method)
[junit4:junit4] 2> at java.util.TimerThread.mainLoop(Timer.java:509)
[junit4:junit4] 2> at java.util.TimerThread.run(Timer.java:462)
[junit4:junit4] 2> 61) Thread[id=1063, name=HashSessionScavenger-27, state=TIMED_WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4:junit4] 2> at java.lang.Object.wait(Native Method)
[junit4:junit4] 2> at java.util.TimerThread.mainLoop(Timer.java:509)
[junit4:junit4] 2> at java.util.TimerThread.run(Timer.java:462)
[junit4:junit4] 2> 62) Thread[id=1093, name=searcherExecutor-706-thread-1, state=WAITING, group=TGRP-ChaosMonkeySafeLeaderTest]
[junit4:junit4] 2> at sun.misc.Unsafe.park(Native Method)
[junit4:junit4] 2> at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
[junit4:junit4] 2> at java.util.concurrent.locks.AbstractQueuedSynchronizer$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> NOTE: test params are: codec=Lucene42: {range_facet_l=PostingsFormat(name=Lucene41WithOrds), text=PostingsFormat(name=MockSep), _version_=PostingsFormat(name=Lucene41WithOrds), rnd_b=PostingsFormat(name=MockRandom), intDefault=PostingsFormat(name=Lucene41WithOrds), id=PostingsFormat(name=MockRandom), timestamp=PostingsFormat(name=Lucene41WithOrds), a_t=PostingsFormat(name=Lucene41WithOrds), range_facet_sl=PostingsFormat(name=MockSep), range_facet_si=Lucene41(blocksize=128), other_tl1=PostingsFormat(name=Lucene41WithOrds), multiDefault=Lucene41(blocksize=128), a_si=Lucene41(blocksize=128)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=es_EC, timezone=America/St_Vincent
[junit4:junit4] 2> NOTE: Windows 7 6.1 x86/Sun Microsystems Inc. 1.6.0_45 (32-bit)/cpus=2,threads=168,free=145501136,total=201981952
[junit4:junit4] 2> NOTE: All tests run in this JVM: [ClusterStateTest, TestAddFieldRealTimeGet, TestFunctionQuery, CurrencyFieldXmlFileTest, TestStressRecovery, TestMaxScoreQueryParser, SolrTestCaseJ4Test, TestHashPartitioner, XsltUpdateRequestHandlerTest, TestRandomDVFaceting, SolrPluginUtilsTest, UUIDFieldTest, DefaultValueUpdateProcessorTest, TestCodecSupport, ShardRoutingCustomTest, CircularListTest, TestClassNameShortening, QueryEqualityTest, TestAtomicUpdateErrorCases, DocumentBuilderTest, WordBreakSolrSpellCheckerTest, TestSchemaNameResource, TestCollationKeyRangeQueries, TestValueSourceCache, SpatialFilterTest, TestFieldTypeCollectionResource, TestUpdate, TestMergePolicyConfig, ConvertedLegacyTest, BinaryUpdateRequestHandlerTest, PrimUtilsTest, SuggesterTSTTest, UpdateRequestProcessorFactoryTest, IndexBasedSpellCheckerTest, TestCharFilters, TestCoreContainer, TestFoldingMultitermQuery, TestSolrDeletionPolicy2, TestQueryTypes, TestDynamicFieldResource, SpellingQueryConverterTest, TestPhraseSuggestions, TestQuerySenderNoQuery, BadIndexSchemaTest, EchoParamsTest, SpellCheckCollatorTest, TestLuceneMatchVersion, TestComponentsName, DisMaxRequestHandlerTest, MoreLikeThisHandlerTest, CacheHeaderTest, DateMathParserTest, TestRangeQuery, TestCoreDiscovery, MinimalSchemaTest, SolrIndexConfigTest, SortByFunctionTest, SliceStateTest, TestSolr4Spatial, TestZkChroot, CurrencyFieldOpenExchangeTest, BasicFunctionalityTest, PeerSyncTest, TestStressLucene, TestBadConfig, NotRequiredUniqueKeyTest, TestRealTimeGet, TestGroupingSearch, TestOmitPositions, TestSystemIdResolver, TestShardHandlerFactory, TestSort, BadComponentTest, ZkSolrClientTest, SampleTest, SolrCoreCheckLockOnStartupTest, UnloadDistributedZkTest, TestJmxMonitoredMap, DistributedTermsComponentTest, SolrRequestParserTest, StandardRequestHandlerTest, SpellCheckComponentTest, ChaosMonkeySafeLeaderTest]
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeySafeLeaderTest -Dtests.seed=C175E917F746EF2C -Dtests.slow=true -Dtests.locale=es_EC -Dtests.timezone=America/St_Vincent -Dtests.file.encoding=ISO-8859-1
[junit4:junit4] ERROR 0.00s | ChaosMonkeySafeLeaderTest (suite) <<<
[junit4:junit4] > Throwable #1: java.lang.Exception: Suite timeout exceeded (>= 7200000 msec).
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([C175E917F746EF2C]:0)
[junit4:junit4] Completed in 7344.05s, 1 test, 2 errors <<< FAILURES!
[...truncated 640 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:392: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:372: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build.xml:181: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\common-build.xml:437: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1246: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:890: There were test failures: 298 suites, 1256 tests, 1 suite-level error, 1 error, 771 ignored (3 assumptions)
Total time: 170 minutes 39 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.6.0_45 -server -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure