lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Policeman Jenkins Server <jenk...@thetaphi.de>
Subject [JENKINS] Lucene-Solr-4.x-Windows (32bit/jdk1.7.0_10) - Build # 2522 - Failure!
Date Mon, 11 Feb 2013 11:36:03 GMT
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/2522/
Java: 32bit/jdk1.7.0_10 -client -XX:+UseConcMarkSweepGC

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

Error Message:
document count mismatch.  control=1259 sum(shards)=1260 cloudClient=1260

Stack Trace:
java.lang.AssertionError: document count mismatch.  control=1259 sum(shards)=1260 cloudClient=1260
	at __randomizedtesting.SeedInfo.seed([1B84F2779348E815:9A627C6FE4178829]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1042)
	at org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.doTest(ChaosMonkeySafeLeaderTest.java:131)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:794)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(Method.java:601)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
	at java.lang.Thread.run(Thread.java:722)




Build Log:
[...truncated 8608 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
[junit4:junit4]   2> 0 T444 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /mi/b
[junit4:junit4]   2> 0 T444 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-1360580561365
[junit4:junit4]   2> 0 T444 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 0 T445 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4]   2> 0 T445 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 0 T445 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4]   2> 0 T445 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4]   2> 17 T445 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 17 T445 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\zookeeper\server1\data\version-2\snapshot.0
[junit4:junit4]   2> 117 T444 oasc.ZkTestServer.run start zk server on port:49782
[junit4:junit4]   2> 117 T444 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49782 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@1c0a1fa
[junit4:junit4]   2> 117 T444 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 117 T450 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:49782. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 117 T450 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:49782, initiating session
[junit4:junit4]   2> 117 T446 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:49785
[junit4:junit4]   2> 117 T446 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:49785
[junit4:junit4]   2> 117 T448 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 134 T448 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cc8ebc9e60000 with negotiated timeout 10000 for client /127.0.0.1:49785
[junit4:junit4]   2> 134 T450 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:49782, sessionid = 0x13cc8ebc9e60000, negotiated timeout = 10000
[junit4:junit4]   2> 134 T451 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c0a1fa name:ZooKeeperConnection Watcher:127.0.0.1:49782 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 134 T444 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 134 T444 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 134 T449 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cc8ebc9e60000
[junit4:junit4]   2> 150 T451 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 150 T444 oaz.ZooKeeper.close Session: 0x13cc8ebc9e60000 closed
[junit4:junit4]   2> 150 T446 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:49785 which had sessionid 0x13cc8ebc9e60000
[junit4:junit4]   2> 150 T444 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49782/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@983b0c
[junit4:junit4]   2> 150 T444 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 150 T452 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:49782. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 150 T452 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:49782, initiating session
[junit4:junit4]   2> 150 T446 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:49788
[junit4:junit4]   2> 150 T446 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:49788
[junit4:junit4]   2> 150 T448 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cc8ebc9e60001 with negotiated timeout 10000 for client /127.0.0.1:49788
[junit4:junit4]   2> 150 T452 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:49782, sessionid = 0x13cc8ebc9e60001, negotiated timeout = 10000
[junit4:junit4]   2> 150 T453 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@983b0c name:ZooKeeperConnection Watcher:127.0.0.1:49782/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 150 T444 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 150 T444 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 167 T444 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 184 T444 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 184 T444 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 200 T444 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig.xml to /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 200 T444 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 217 T444 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> 217 T444 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 217 T444 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> 217 T444 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 234 T444 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> 234 T444 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 250 T444 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> 250 T444 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 250 T444 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> 250 T444 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 267 T444 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> 267 T444 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 267 T444 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> 267 T444 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 284 T444 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> 284 T444 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 300 T449 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cc8ebc9e60001
[junit4:junit4]   2> 300 T453 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 300 T446 oazs.NIOServerCnxn.doIO WARNING caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13cc8ebc9e60001, 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:722)
[junit4:junit4]   2> 
[junit4:junit4]   2> 300 T446 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:49788 which had sessionid 0x13cc8ebc9e60001
[junit4:junit4]   2> 300 T444 oaz.ZooKeeper.close Session: 0x13cc8ebc9e60001 closed
[junit4:junit4]   2> 701 T444 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 717 T444 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49789
[junit4:junit4]   2> 717 T444 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 717 T444 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 717 T444 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-1360580561665
[junit4:junit4]   2> 717 T444 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1360580561665\solr.xml
[junit4:junit4]   2> 717 T444 oasc.CoreContainer.<init> New CoreContainer 18331974
[junit4:junit4]   2> 717 T444 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-1360580561665\'
[junit4:junit4]   2> 717 T444 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-1360580561665\'
[junit4:junit4]   2> 784 T444 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 60000
[junit4:junit4]   2> 784 T444 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 801 T444 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 801 T444 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 801 T444 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 801 T444 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 801 T444 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 801 T444 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 801 T444 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 801 T444 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=60000&connTimeout=15000&retry=false
[junit4:junit4]   2> 817 T444 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 834 T444 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:49782/solr
[junit4:junit4]   2> 834 T444 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 834 T444 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49782 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@170b635
[junit4:junit4]   2> 851 T444 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 851 T463 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:49782. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 851 T463 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:49782, initiating session
[junit4:junit4]   2> 851 T446 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:49794
[junit4:junit4]   2> 851 T446 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:49794
[junit4:junit4]   2> 867 T448 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cc8ebc9e60002 with negotiated timeout 20000 for client /127.0.0.1:49794
[junit4:junit4]   2> 867 T463 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:49782, sessionid = 0x13cc8ebc9e60002, negotiated timeout = 20000
[junit4:junit4]   2> 867 T464 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@170b635 name:ZooKeeperConnection Watcher:127.0.0.1:49782 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 867 T444 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 867 T449 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cc8ebc9e60002
[junit4:junit4]   2> 867 T446 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:49794 which had sessionid 0x13cc8ebc9e60002
[junit4:junit4]   2> 867 T444 oaz.ZooKeeper.close Session: 0x13cc8ebc9e60002 closed
[junit4:junit4]   2> 867 T464 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 884 T444 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=60000&connTimeout=15000
[junit4:junit4]   2> 884 T444 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49782/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@6be0d6
[junit4:junit4]   2> 884 T444 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 884 T465 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:49782. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 884 T465 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:49782, initiating session
[junit4:junit4]   2> 901 T446 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:49797
[junit4:junit4]   2> 901 T446 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:49797
[junit4:junit4]   2> 901 T448 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cc8ebc9e60003 with negotiated timeout 20000 for client /127.0.0.1:49797
[junit4:junit4]   2> 901 T465 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:49782, sessionid = 0x13cc8ebc9e60003, negotiated timeout = 20000
[junit4:junit4]   2> 901 T466 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6be0d6 name:ZooKeeperConnection Watcher:127.0.0.1:49782/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 901 T444 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 901 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60003 type:create cxid:0x2 zxid:0x1a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 901 T444 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 917 T444 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49789_mi%2Fb
[junit4:junit4]   2> 917 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60003 type:delete cxid:0x8 zxid:0x1c txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:49789_mi%2Fb Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:49789_mi%2Fb
[junit4:junit4]   2> 917 T444 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49789_mi%2Fb
[junit4:junit4]   2> 934 T444 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 951 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60003 type:delete cxid:0x16 zxid:0x21 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4]   2> 951 T444 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 951 T444 oasc.Overseer.start Overseer (id=89167007670730755-127.0.0.1:49789_mi%2Fb-n_0000000000) starting
[junit4:junit4]   2> 967 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60003 type:create cxid:0x1b zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 967 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60003 type:create cxid:0x1c zxid:0x24 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 967 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60003 type:create cxid:0x1d zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 967 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60003 type:create cxid:0x1e zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 984 T468 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 984 T444 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 984 T444 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 1001 T467 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 1001 T469 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-1360580561665\collection1
[junit4:junit4]   2> 1001 T469 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 1017 T469 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 1017 T469 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 1017 T469 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-1360580561665\collection1\'
[junit4:junit4]   2> 1017 T469 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-1360580561665/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 1017 T469 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-1360580561665/collection1/lib/README' to classloader
[junit4:junit4]   2> 1101 T469 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4]   2> 1201 T469 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 1201 T469 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 1218 T469 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 2185 T469 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 2202 T469 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 2202 T469 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 2235 T469 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2235 T469 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2252 T469 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2252 T469 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2252 T469 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-1360580561665\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365/control/data\
[junit4:junit4]   2> 2252 T469 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b4b8fc
[junit4:junit4]   2> 2252 T469 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 2285 T469 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-1360580561365\control\data forceNew:false
[junit4:junit4]   2> 2285 T469 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\control\data
[junit4:junit4]   2> 2285 T469 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365/control/data\index/
[junit4:junit4]   2> 2285 T469 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\control\data\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 2285 T469 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-1360580561365\control\data\index forceNew:false
[junit4:junit4]   2> 2302 T469 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(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-1360580561365\control\data\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@c1edc6),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 2302 T469 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 2302 T469 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\control\data\index
[junit4:junit4]   2> 2302 T469 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 2302 T469 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 2302 T469 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 2302 T469 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 2302 T469 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 2302 T469 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 2302 T469 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 2302 T469 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 2302 T469 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 2302 T469 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 2302 T469 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 2302 T469 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 2302 T469 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 2302 T469 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 2302 T469 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 2302 T469 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 2302 T469 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 2302 T469 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2302 T469 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2302 T469 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2302 T469 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2302 T469 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2302 T469 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2302 T469 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2302 T469 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2302 T469 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 2302 T469 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 2318 T469 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 2318 T469 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 2318 T469 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4]   2> 2335 T469 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\control\data
[junit4:junit4]   2> 2335 T469 oass.SolrIndexSearcher.<init> Opening Searcher@18fe74c main
[junit4:junit4]   2> 2335 T469 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 2335 T469 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 2335 T469 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 2352 T469 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 2418 T470 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@18fe74c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 2418 T469 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 2418 T469 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 2418 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60003 type:create cxid:0x51 zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue Error:KeeperErrorCode = NoNode for /solr/overseer/queue
[junit4:junit4]   2> 2602 T467 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2602 T467 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:49789_mi%2Fb",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:49789/mi/b"}
[junit4:junit4]   2> 2602 T467 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4]   2> 2602 T467 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 2602 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60003 type:create cxid:0x59 zxid:0x2c txntype:-1 reqpath:n/a Error Path:/solr/overseer/queue-work Error:KeeperErrorCode = NoNode for /solr/overseer/queue-work
[junit4:junit4]   2> 2652 T466 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> 3502 T469 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 3502 T469 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49789/mi/b collection:control_collection shard:shard1
[junit4:junit4]   2> 3502 T469 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4]   2> 3519 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60003 type:delete cxid:0x73 zxid:0x36 txntype:-1 reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4]   2> 3519 T469 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 3519 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60003 type:create cxid:0x74 zxid:0x37 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3536 T469 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 3536 T469 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 3536 T469 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49789/mi/b/collection1/
[junit4:junit4]   2> 3536 T469 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 3536 T469 oasc.SyncStrategy.syncToMe http://127.0.0.1:49789/mi/b/collection1/ has no replicas
[junit4:junit4]   2> 3536 T469 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49789/mi/b/collection1/
[junit4:junit4]   2> 3536 T469 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4]   2> 3552 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60003 type:create cxid:0x7e zxid:0x3b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4253 T467 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4269 T466 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> 4353 T469 oasc.ZkController.register We are http://127.0.0.1:49789/mi/b/collection1/ and leader is http://127.0.0.1:49789/mi/b/collection1/
[junit4:junit4]   2> 4353 T469 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49789/mi/b
[junit4:junit4]   2> 4353 T469 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 4353 T469 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 4353 T469 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 4370 T469 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 4370 T444 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 4370 T444 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 4370 T444 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 4386 T444 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 4386 T444 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49782/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@740d0a
[junit4:junit4]   2> 4403 T444 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4403 T471 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:49782. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 4403 T471 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:49782, initiating session
[junit4:junit4]   2> 4403 T446 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:49800
[junit4:junit4]   2> 4403 T446 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:49800
[junit4:junit4]   2> 4403 T448 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cc8ebc9e60004 with negotiated timeout 10000 for client /127.0.0.1:49800
[junit4:junit4]   2> 4403 T471 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:49782, sessionid = 0x13cc8ebc9e60004, negotiated timeout = 10000
[junit4:junit4]   2> 4403 T472 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@740d0a name:ZooKeeperConnection Watcher:127.0.0.1:49782/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4420 T444 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4420 T444 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 4420 T444 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 4786 T444 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 4786 T444 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49801
[junit4:junit4]   2> 4786 T444 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 4786 T444 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 4786 T444 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-1360580565785
[junit4:junit4]   2> 4786 T444 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1360580565785\solr.xml
[junit4:junit4]   2> 4786 T444 oasc.CoreContainer.<init> New CoreContainer 28359433
[junit4:junit4]   2> 4786 T444 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-1360580565785\'
[junit4:junit4]   2> 4786 T444 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-1360580565785\'
[junit4:junit4]   2> 4853 T444 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 60000
[junit4:junit4]   2> 4853 T444 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 4853 T444 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 4853 T444 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 4853 T444 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 4853 T444 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 4853 T444 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 4853 T444 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 4853 T444 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 4853 T444 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=60000&connTimeout=15000&retry=false
[junit4:junit4]   2> 4870 T444 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 4920 T444 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:49782/solr
[junit4:junit4]   2> 4920 T444 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 4920 T444 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49782 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@8ae265
[junit4:junit4]   2> 4920 T444 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4920 T482 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:49782. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 4920 T482 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:49782, initiating session
[junit4:junit4]   2> 4920 T446 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:49806
[junit4:junit4]   2> 4920 T446 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:49806
[junit4:junit4]   2> 4937 T448 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cc8ebc9e60005 with negotiated timeout 20000 for client /127.0.0.1:49806
[junit4:junit4]   2> 4937 T482 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:49782, sessionid = 0x13cc8ebc9e60005, negotiated timeout = 20000
[junit4:junit4]   2> 4937 T483 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8ae265 name:ZooKeeperConnection Watcher:127.0.0.1:49782 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4937 T444 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4937 T449 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cc8ebc9e60005
[junit4:junit4]   2> 4953 T444 oaz.ZooKeeper.close Session: 0x13cc8ebc9e60005 closed
[junit4:junit4]   2> 4953 T483 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 4953 T446 oazs.NIOServerCnxn.doIO WARNING caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13cc8ebc9e60005, 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:722)
[junit4:junit4]   2> 
[junit4:junit4]   2> 4953 T444 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=60000&connTimeout=15000
[junit4:junit4]   2> 4953 T446 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:49806 which had sessionid 0x13cc8ebc9e60005
[junit4:junit4]   2> 4953 T444 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49782/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@421ef8
[junit4:junit4]   2> 4953 T444 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4953 T484 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:49782. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 4970 T484 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:49782, initiating session
[junit4:junit4]   2> 4970 T446 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:49809
[junit4:junit4]   2> 4970 T446 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:49809
[junit4:junit4]   2> 4970 T448 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cc8ebc9e60006 with negotiated timeout 20000 for client /127.0.0.1:49809
[junit4:junit4]   2> 4970 T484 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:49782, sessionid = 0x13cc8ebc9e60006, negotiated timeout = 20000
[junit4:junit4]   2> 4970 T485 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@421ef8 name:ZooKeeperConnection Watcher:127.0.0.1:49782/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4970 T444 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4970 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60006 type:create cxid:0x1 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4970 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60006 type:create cxid:0x2 zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4987 T444 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 4987 T444 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49801_mi%2Fb
[junit4:junit4]   2> 4987 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60006 type:delete cxid:0x9 zxid:0x4b txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:49801_mi%2Fb Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:49801_mi%2Fb
[junit4:junit4]   2> 4987 T444 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49801_mi%2Fb
[junit4:junit4]   2> 5003 T485 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5003 T472 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5003 T466 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5003 T466 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> 5003 T486 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-1360580565785\collection1
[junit4:junit4]   2> 5003 T486 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 5020 T486 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 5020 T486 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 5020 T486 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-1360580565785\collection1\'
[junit4:junit4]   2> 5020 T486 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-1360580565785/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 5020 T486 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-1360580565785/collection1/lib/README' to classloader
[junit4:junit4]   2> 5087 T486 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4]   2> 5203 T486 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 5203 T486 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 5220 T486 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 5904 T467 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5920 T467 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:49789_mi%2Fb",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:49789/mi/b"}
[junit4:junit4]   2> 5920 T472 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> 5920 T466 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> 5920 T485 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> 6087 T486 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 6104 T486 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 6104 T486 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 6137 T486 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 6137 T486 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 6137 T486 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 6137 T486 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 6137 T486 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-1360580565785\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365/jetty1\
[junit4:junit4]   2> 6137 T486 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b4b8fc
[junit4:junit4]   2> 6137 T486 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 6154 T486 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-1360580561365\jetty1 forceNew:false
[junit4:junit4]   2> 6154 T486 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\jetty1
[junit4:junit4]   2> 6154 T486 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365/jetty1\index/
[junit4:junit4]   2> 6154 T486 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\jetty1\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 6154 T486 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-1360580561365\jetty1\index forceNew:false
[junit4:junit4]   2> 6171 T486 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(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-1360580561365\jetty1\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@962ef0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 6171 T486 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 6187 T486 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\jetty1\index
[junit4:junit4]   2> 6187 T486 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 6187 T486 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 6187 T486 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 6187 T486 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 6187 T486 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 6187 T486 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 6187 T486 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 6187 T486 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 6187 T486 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 6187 T486 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 6187 T486 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 6187 T486 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 6187 T486 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 6187 T486 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 6187 T486 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 6187 T486 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 6187 T486 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 6187 T486 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6187 T486 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6187 T486 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6187 T486 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6187 T486 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6187 T486 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6204 T486 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6204 T486 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 6204 T486 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 6204 T486 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 6221 T486 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 6221 T486 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 6221 T486 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4]   2> 6221 T486 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\jetty1
[junit4:junit4]   2> 6237 T486 oass.SolrIndexSearcher.<init> Opening Searcher@1738944 main
[junit4:junit4]   2> 6237 T486 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 6237 T486 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 6237 T486 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 6271 T486 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 6337 T487 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1738944 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 6354 T486 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 6354 T486 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 7521 T467 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 7521 T467 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"3",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:49801_mi%2Fb",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:49801/mi/b"}
[junit4:junit4]   2> 7521 T467 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 3
[junit4:junit4]   2> 7521 T467 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 7605 T485 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> 7605 T466 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> 7605 T472 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> 8489 T486 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 8489 T486 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49801/mi/b collection:collection1 shard:shard1
[junit4:junit4]   2> 8489 T486 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 8589 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60006 type:delete cxid:0x47 zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4]   2> 8605 T486 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 8605 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60006 type:create cxid:0x48 zxid:0x5c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8672 T486 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 8672 T486 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 8672 T486 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49801/mi/b/collection1/
[junit4:junit4]   2> 8672 T486 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 8672 T486 oasc.SyncStrategy.syncToMe http://127.0.0.1:49801/mi/b/collection1/ has no replicas
[junit4:junit4]   2> 8672 T486 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49801/mi/b/collection1/
[junit4:junit4]   2> 8672 T486 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 8722 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60006 type:create cxid:0x52 zxid:0x60 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 9222 T467 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9256 T466 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> 9256 T472 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> 9256 T485 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> 9329 T486 oasc.ZkController.register We are http://127.0.0.1:49801/mi/b/collection1/ and leader is http://127.0.0.1:49801/mi/b/collection1/
[junit4:junit4]   2> 9329 T486 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49801/mi/b
[junit4:junit4]   2> 9329 T486 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 9329 T486 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 9329 T486 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 9329 T486 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9329 T444 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 9329 T444 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 9329 T444 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 9824 T444 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 9824 T444 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49810
[junit4:junit4]   2> 9824 T444 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 9824 T444 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 9824 T444 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-1360580570713
[junit4:junit4]   2> 9824 T444 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1360580570713\solr.xml
[junit4:junit4]   2> 9824 T444 oasc.CoreContainer.<init> New CoreContainer 5461026
[junit4:junit4]   2> 9824 T444 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-1360580570713\'
[junit4:junit4]   2> 9824 T444 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-1360580570713\'
[junit4:junit4]   2> 9898 T444 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 60000
[junit4:junit4]   2> 9898 T444 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 9898 T444 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 9898 T444 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 9898 T444 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 9898 T444 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 9898 T444 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 9898 T444 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 9898 T444 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 9898 T444 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=60000&connTimeout=15000&retry=false
[junit4:junit4]   2> 9916 T444 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 9953 T444 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:49782/solr
[junit4:junit4]   2> 9953 T444 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 9953 T444 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49782 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1eb5563
[junit4:junit4]   2> 9971 T444 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 9971 T497 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:49782. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 9971 T497 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:49782, initiating session
[junit4:junit4]   2> 9971 T446 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:49815
[junit4:junit4]   2> 9971 T446 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:49815
[junit4:junit4]   2> 9990 T448 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cc8ebc9e60007 with negotiated timeout 20000 for client /127.0.0.1:49815
[junit4:junit4]   2> 9990 T497 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:49782, sessionid = 0x13cc8ebc9e60007, negotiated timeout = 20000
[junit4:junit4]   2> 9990 T498 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1eb5563 name:ZooKeeperConnection Watcher:127.0.0.1:49782 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 9990 T444 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 9990 T449 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cc8ebc9e60007
[junit4:junit4]   2> 9990 T446 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:49815 which had sessionid 0x13cc8ebc9e60007
[junit4:junit4]   2> 9990 T498 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 9990 T444 oaz.ZooKeeper.close Session: 0x13cc8ebc9e60007 closed
[junit4:junit4]   2> 9990 T444 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=60000&connTimeout=15000
[junit4:junit4]   2> 9990 T444 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49782/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@19480c0
[junit4:junit4]   2> 10008 T444 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 10008 T499 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:49782. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 10008 T499 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:49782, initiating session
[junit4:junit4]   2> 10008 T446 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:49818
[junit4:junit4]   2> 10008 T446 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:49818
[junit4:junit4]   2> 10008 T448 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cc8ebc9e60008 with negotiated timeout 20000 for client /127.0.0.1:49818
[junit4:junit4]   2> 10008 T499 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:49782, sessionid = 0x13cc8ebc9e60008, negotiated timeout = 20000
[junit4:junit4]   2> 10008 T500 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19480c0 name:ZooKeeperConnection Watcher:127.0.0.1:49782/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 10008 T444 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 10008 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60008 type:create cxid:0x1 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 10008 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60008 type:create cxid:0x2 zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 10008 T444 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 10026 T444 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49810_mi%2Fb
[junit4:junit4]   2> 10026 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60008 type:delete cxid:0x9 zxid:0x6f txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:49810_mi%2Fb Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:49810_mi%2Fb
[junit4:junit4]   2> 10026 T444 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49810_mi%2Fb
[junit4:junit4]   2> 10026 T485 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 10026 T485 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> 10026 T500 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 10026 T472 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 10026 T472 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> 10026 T466 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 10026 T466 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> 10063 T501 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-1360580570713\collection1
[junit4:junit4]   2> 10063 T501 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 10063 T501 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 10063 T501 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 10063 T501 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-1360580570713\collection1\'
[junit4:junit4]   2> 10063 T501 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-1360580570713/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 10063 T501 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-1360580570713/collection1/lib/README' to classloader
[junit4:junit4]   2> 10155 T501 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4]   2> 10283 T501 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 10283 T501 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 10301 T501 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 11035 T467 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11035 T467 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"3",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:49801_mi%2Fb",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:49801/mi/b"}
[junit4:junit4]   2> 11054 T485 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> 11072 T466 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> 11072 T472 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> 11072 T500 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> 11604 T501 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 11622 T501 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 11622 T501 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 11677 T501 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 11677 T501 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 11677 T501 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 11677 T501 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 11696 T501 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-1360580570713\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365/jetty2\
[junit4:junit4]   2> 11696 T501 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b4b8fc
[junit4:junit4]   2> 11696 T501 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 11696 T501 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-1360580561365\jetty2 forceNew:false
[junit4:junit4]   2> 11696 T501 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\jetty2
[junit4:junit4]   2> 11696 T501 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365/jetty2\index/
[junit4:junit4]   2> 11696 T501 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\jetty2\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 11696 T501 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-1360580561365\jetty2\index forceNew:false
[junit4:junit4]   2> 11714 T501 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(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-1360580561365\jetty2\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@1504427),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 11714 T501 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 11714 T501 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\jetty2\index
[junit4:junit4]   2> 11714 T501 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 11714 T501 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 11714 T501 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 11714 T501 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 11714 T501 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 11714 T501 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 11714 T501 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 11714 T501 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 11732 T501 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 11732 T501 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 11732 T501 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 11732 T501 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 11732 T501 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 11732 T501 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 11732 T501 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 11732 T501 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 11732 T501 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 11732 T501 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 11732 T501 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 11732 T501 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 11732 T501 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 11732 T501 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 11732 T501 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 11732 T501 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 11732 T501 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 11751 T501 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 11751 T501 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 11751 T501 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 11769 T501 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 11769 T501 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4]   2> 11769 T501 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\jetty2
[junit4:junit4]   2> 11769 T501 oass.SolrIndexSearcher.<init> Opening Searcher@ec143 main
[junit4:junit4]   2> 11769 T501 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 11769 T501 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 11769 T501 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 11787 T501 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 11879 T502 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@ec143 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 11897 T501 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 11897 T501 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 12833 T467 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12833 T467 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"3",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:49810_mi%2Fb",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:49810/mi/b"}
[junit4:junit4]   2> 12833 T467 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4]   2> 12833 T467 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4]   2> 12851 T466 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> 12851 T472 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> 12851 T485 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> 12851 T500 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> 13071 T501 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 13071 T501 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49810/mi/b collection:collection1 shard:shard2
[junit4:junit4]   2> 13071 T501 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4]   2> 13090 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60008 type:delete cxid:0x46 zxid:0x7e txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard2 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard2
[junit4:junit4]   2> 13090 T501 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 13090 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60008 type:create cxid:0x47 zxid:0x7f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 13108 T501 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 13108 T501 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 13108 T501 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49810/mi/b/collection1/
[junit4:junit4]   2> 13108 T501 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 13108 T501 oasc.SyncStrategy.syncToMe http://127.0.0.1:49810/mi/b/collection1/ has no replicas
[junit4:junit4]   2> 13108 T501 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49810/mi/b/collection1/
[junit4:junit4]   2> 13108 T501 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4]   2> 13108 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60008 type:create cxid:0x50 zxid:0x82 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 14612 T467 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14649 T466 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> 14649 T485 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> 14649 T500 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> 14649 T472 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> 14741 T501 oasc.ZkController.register We are http://127.0.0.1:49810/mi/b/collection1/ and leader is http://127.0.0.1:49810/mi/b/collection1/
[junit4:junit4]   2> 14741 T501 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49810/mi/b
[junit4:junit4]   2> 14741 T501 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 14741 T501 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 14741 T501 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 14741 T501 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 14741 T444 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 14741 T444 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 14741 T444 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 15218 T444 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 15218 T444 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49819
[junit4:junit4]   2> 15218 T444 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 15218 T444 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 15218 T444 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-1360580576106
[junit4:junit4]   2> 15218 T444 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1360580576106\solr.xml
[junit4:junit4]   2> 15218 T444 oasc.CoreContainer.<init> New CoreContainer 33000747
[junit4:junit4]   2> 15218 T444 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-1360580576106\'
[junit4:junit4]   2> 15218 T444 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-1360580576106\'
[junit4:junit4]   2> 15309 T444 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 60000
[junit4:junit4]   2> 15309 T444 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 15309 T444 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 15309 T444 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 15309 T444 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 15309 T444 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 15309 T444 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 15309 T444 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 15309 T444 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 15309 T444 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=60000&connTimeout=15000&retry=false
[junit4:junit4]   2> 15328 T444 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 15365 T444 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:49782/solr
[junit4:junit4]   2> 15365 T444 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 15365 T444 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49782 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1fb258f
[junit4:junit4]   2> 15365 T444 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 15365 T512 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:49782. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 15383 T512 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:49782, initiating session
[junit4:junit4]   2> 15383 T446 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:49824
[junit4:junit4]   2> 15383 T446 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:49824
[junit4:junit4]   2> 15383 T448 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cc8ebc9e60009 with negotiated timeout 20000 for client /127.0.0.1:49824
[junit4:junit4]   2> 15383 T512 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:49782, sessionid = 0x13cc8ebc9e60009, negotiated timeout = 20000
[junit4:junit4]   2> 15383 T513 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1fb258f name:ZooKeeperConnection Watcher:127.0.0.1:49782 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 15383 T444 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 15401 T449 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cc8ebc9e60009
[junit4:junit4]   2> 15401 T446 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:49824 which had sessionid 0x13cc8ebc9e60009
[junit4:junit4]   2> 15401 T444 oaz.ZooKeeper.close Session: 0x13cc8ebc9e60009 closed
[junit4:junit4]   2> 15401 T513 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 15401 T444 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=60000&connTimeout=15000
[junit4:junit4]   2> 15401 T444 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49782/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@152606d
[junit4:junit4]   2> 15420 T444 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 15420 T514 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:49782. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 15420 T514 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:49782, initiating session
[junit4:junit4]   2> 15420 T446 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:49827
[junit4:junit4]   2> 15420 T446 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:49827
[junit4:junit4]   2> 15420 T448 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cc8ebc9e6000a with negotiated timeout 20000 for client /127.0.0.1:49827
[junit4:junit4]   2> 15420 T514 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:49782, sessionid = 0x13cc8ebc9e6000a, negotiated timeout = 20000
[junit4:junit4]   2> 15420 T515 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@152606d name:ZooKeeperConnection Watcher:127.0.0.1:49782/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 15420 T444 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 15420 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e6000a type:create cxid:0x1 zxid:0x8f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 15420 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e6000a type:create cxid:0x2 zxid:0x90 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 15420 T444 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 15420 T444 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49819_mi%2Fb
[junit4:junit4]   2> 15438 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e6000a type:delete cxid:0x9 zxid:0x91 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:49819_mi%2Fb Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:49819_mi%2Fb
[junit4:junit4]   2> 15438 T444 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49819_mi%2Fb
[junit4:junit4]   2> 15438 T500 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> 15438 T515 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 15438 T472 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 15438 T472 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> 15438 T466 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 15438 T466 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> 15438 T485 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 15438 T485 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> 15456 T500 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 15456 T516 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-1360580576106\collection1
[junit4:junit4]   2> 15456 T516 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 15456 T516 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 15456 T516 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 15475 T516 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-1360580576106\collection1\'
[junit4:junit4]   2> 15475 T516 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-1360580576106/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 15475 T516 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-1360580576106/collection1/lib/README' to classloader
[junit4:junit4]   2> 15566 T516 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4]   2> 15695 T516 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 15695 T516 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 15695 T516 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 16447 T467 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 16447 T467 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"3",
[junit4:junit4]   2> 	  "shard":"shard2",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:49810_mi%2Fb",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:49810/mi/b"}
[junit4:junit4]   2> 16465 T485 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> 16465 T515 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> 16465 T466 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> 16465 T472 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> 16465 T500 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> 16942 T516 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 16960 T516 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 16979 T516 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 16997 T516 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 16997 T516 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 17015 T516 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 17015 T516 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 17015 T516 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-1360580576106\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365/jetty3\
[junit4:junit4]   2> 17015 T516 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b4b8fc
[junit4:junit4]   2> 17015 T516 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 17015 T516 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-1360580561365\jetty3 forceNew:false
[junit4:junit4]   2> 17034 T516 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\jetty3
[junit4:junit4]   2> 17034 T516 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365/jetty3\index/
[junit4:junit4]   2> 17034 T516 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\jetty3\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 17034 T516 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-1360580561365\jetty3\index forceNew:false
[junit4:junit4]   2> 17052 T516 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(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-1360580561365\jetty3\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@87abd8),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 17052 T516 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 17052 T516 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\jetty3\index
[junit4:junit4]   2> 17052 T516 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 17071 T516 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 17071 T516 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 17071 T516 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 17071 T516 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 17071 T516 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 17071 T516 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 17071 T516 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 17071 T516 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 17071 T516 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 17071 T516 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 17071 T516 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 17071 T516 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 17071 T516 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 17071 T516 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 17071 T516 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 17071 T516 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 17071 T516 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 17071 T516 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 17071 T516 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 17071 T516 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 17071 T516 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 17089 T516 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 17089 T516 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 17089 T516 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 17089 T516 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 17089 T516 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 17089 T516 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 17107 T516 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 17107 T516 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4]   2> 17107 T516 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\jetty3
[junit4:junit4]   2> 17107 T516 oass.SolrIndexSearcher.<init> Opening Searcher@2cb881 main
[junit4:junit4]   2> 17126 T516 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 17126 T516 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 17126 T516 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 17126 T516 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 17236 T517 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2cb881 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 17254 T516 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 17254 T516 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 18245 T467 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 18245 T467 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"3",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:49819_mi%2Fb",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:49819/mi/b"}
[junit4:junit4]   2> 18245 T467 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4]   2> 18245 T467 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard3
[junit4:junit4]   2> 18263 T466 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> 18263 T485 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> 18263 T472 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> 18263 T515 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> 18263 T500 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> 18428 T516 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 18428 T516 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49819/mi/b collection:collection1 shard:shard3
[junit4:junit4]   2> 18428 T516 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4:junit4]   2> 18446 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e6000a type:delete cxid:0x46 zxid:0xa0 txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders/shard3 Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders/shard3
[junit4:junit4]   2> 18446 T516 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 18446 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e6000a type:create cxid:0x47 zxid:0xa1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 18465 T516 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 18465 T516 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 18465 T516 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49819/mi/b/collection1/
[junit4:junit4]   2> 18465 T516 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 18465 T516 oasc.SyncStrategy.syncToMe http://127.0.0.1:49819/mi/b/collection1/ has no replicas
[junit4:junit4]   2> 18465 T516 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49819/mi/b/collection1/
[junit4:junit4]   2> 18465 T516 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4:junit4]   2> 18483 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e6000a type:create cxid:0x50 zxid:0xa4 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 20024 T467 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 20042 T485 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> 20042 T515 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> 20042 T472 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> 20042 T500 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> 20042 T466 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> 20097 T516 oasc.ZkController.register We are http://127.0.0.1:49819/mi/b/collection1/ and leader is http://127.0.0.1:49819/mi/b/collection1/
[junit4:junit4]   2> 20097 T516 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49819/mi/b
[junit4:junit4]   2> 20097 T516 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 20097 T516 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 20097 T516 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 20097 T516 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 20097 T444 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 20097 T444 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 20097 T444 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 20574 T444 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 20574 T444 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49828
[junit4:junit4]   2> 20574 T444 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 20574 T444 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 20574 T444 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-1360580581499
[junit4:junit4]   2> 20574 T444 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1360580581499\solr.xml
[junit4:junit4]   2> 20574 T444 oasc.CoreContainer.<init> New CoreContainer 19064248
[junit4:junit4]   2> 20574 T444 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-1360580581499\'
[junit4:junit4]   2> 20574 T444 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-1360580581499\'
[junit4:junit4]   2> 20666 T444 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 60000
[junit4:junit4]   2> 20666 T444 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 20666 T444 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 20666 T444 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 20666 T444 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 20666 T444 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 20666 T444 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 20666 T444 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 20666 T444 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 20666 T444 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=60000&connTimeout=15000&retry=false
[junit4:junit4]   2> 20684 T444 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 20721 T444 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:49782/solr
[junit4:junit4]   2> 20721 T444 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 20721 T444 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49782 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@1bcd17b
[junit4:junit4]   2> 20721 T444 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 20721 T527 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:49782. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 20739 T527 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:49782, initiating session
[junit4:junit4]   2> 20739 T446 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:49833
[junit4:junit4]   2> 20739 T446 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:49833
[junit4:junit4]   2> 20739 T448 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cc8ebc9e6000b with negotiated timeout 20000 for client /127.0.0.1:49833
[junit4:junit4]   2> 20739 T527 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:49782, sessionid = 0x13cc8ebc9e6000b, negotiated timeout = 20000
[junit4:junit4]   2> 20739 T528 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1bcd17b name:ZooKeeperConnection Watcher:127.0.0.1:49782 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 20739 T444 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 20739 T449 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cc8ebc9e6000b
[junit4:junit4]   2> 20758 T446 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:49833 which had sessionid 0x13cc8ebc9e6000b
[junit4:junit4]   2> 20758 T528 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 20758 T444 oaz.ZooKeeper.close Session: 0x13cc8ebc9e6000b closed
[junit4:junit4]   2> 20758 T444 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=60000&connTimeout=15000
[junit4:junit4]   2> 20776 T444 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49782/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@f51309
[junit4:junit4]   2> 20776 T444 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 20776 T529 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:49782. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 20776 T529 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:49782, initiating session
[junit4:junit4]   2> 20776 T446 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:49836
[junit4:junit4]   2> 20776 T446 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:49836
[junit4:junit4]   2> 20794 T448 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cc8ebc9e6000c with negotiated timeout 20000 for client /127.0.0.1:49836
[junit4:junit4]   2> 20794 T529 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:49782, sessionid = 0x13cc8ebc9e6000c, negotiated timeout = 20000
[junit4:junit4]   2> 20794 T530 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f51309 name:ZooKeeperConnection Watcher:127.0.0.1:49782/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 20794 T444 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 20794 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e6000c type:create cxid:0x1 zxid:0xb1 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 20794 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e6000c type:create cxid:0x2 zxid:0xb2 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 20794 T444 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 20813 T444 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49828_mi%2Fb
[junit4:junit4]   2> 20813 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e6000c type:delete cxid:0x9 zxid:0xb3 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:49828_mi%2Fb Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:49828_mi%2Fb
[junit4:junit4]   2> 20813 T444 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49828_mi%2Fb
[junit4:junit4]   2> 20813 T515 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> 20813 T500 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> 20813 T485 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 20813 T485 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> 20813 T530 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 20813 T472 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 20831 T472 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> 20831 T466 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 20831 T466 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> 20831 T515 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 20831 T500 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4]   2> 20849 T531 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-1360580581499\collection1
[junit4:junit4]   2> 20849 T531 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 20849 T531 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 20849 T531 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 20849 T531 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-1360580581499\collection1\'
[junit4:junit4]   2> 20849 T531 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-1360580581499/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 20868 T531 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-1360580581499/collection1/lib/README' to classloader
[junit4:junit4]   2> 20960 T531 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4]   2> 21095 T531 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 21095 T531 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 21112 T531 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 21756 T467 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 21756 T467 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"3",
[junit4:junit4]   2> 	  "shard":"shard3",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:49819_mi%2Fb",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:49819/mi/b"}
[junit4:junit4]   2> 21772 T530 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> 21772 T466 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> 21772 T472 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> 21772 T500 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> 21772 T485 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> 21772 T515 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> 22201 T531 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 22218 T531 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 22234 T531 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 22251 T531 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 22251 T531 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 22268 T531 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 22268 T531 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 22268 T531 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-1360580581499\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365/jetty4\
[junit4:junit4]   2> 22268 T531 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b4b8fc
[junit4:junit4]   2> 22268 T531 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 22268 T531 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-1360580561365\jetty4 forceNew:false
[junit4:junit4]   2> 22268 T531 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\jetty4
[junit4:junit4]   2> 22268 T531 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365/jetty4\index/
[junit4:junit4]   2> 22268 T531 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\jetty4\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 22284 T531 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-1360580561365\jetty4\index forceNew:false
[junit4:junit4]   2> 22301 T531 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(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-1360580561365\jetty4\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@182506),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 22301 T531 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 22301 T531 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\jetty4\index
[junit4:junit4]   2> 22301 T531 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 22301 T531 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 22301 T531 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 22301 T531 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 22301 T531 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 22301 T531 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 22301 T531 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 22301 T531 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 22317 T531 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 22317 T531 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 22317 T531 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 22317 T531 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 22317 T531 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 22317 T531 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 22317 T531 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 22317 T531 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 22317 T531 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 22317 T531 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 22317 T531 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 22317 T531 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 22317 T531 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 22317 T531 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 22317 T531 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 22317 T531 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 22334 T531 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 22334 T531 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 22334 T531 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 22334 T531 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 22350 T531 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 22350 T531 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4]   2> 22350 T531 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\jetty4
[junit4:junit4]   2> 22350 T531 oass.SolrIndexSearcher.<init> Opening Searcher@94c035 main
[junit4:junit4]   2> 22367 T531 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 22367 T531 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 22367 T531 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 22383 T531 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 22466 T531 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 22466 T531 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 22466 T532 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@94c035 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 23374 T467 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 23374 T467 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"3",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:49828_mi%2Fb",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:49828/mi/b"}
[junit4:junit4]   2> 23374 T467 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4]   2> 23374 T467 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 23390 T530 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> 23390 T515 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> 23390 T485 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> 23390 T500 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> 23390 T472 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> 23390 T466 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> 23539 T531 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 23539 T531 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49828/mi/b collection:collection1 shard:shard1
[junit4:junit4]   2> 23539 T531 oasc.ZkController.register We are http://127.0.0.1:49828/mi/b/collection1/ and leader is http://127.0.0.1:49801/mi/b/collection1/
[junit4:junit4]   2> 23539 T531 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49828/mi/b
[junit4:junit4]   2> 23539 T531 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 23539 T531 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C19 name=collection1 org.apache.solr.core.SolrCore@1439c61 url=http://127.0.0.1:49828/mi/b/collection1 node=127.0.0.1:49828_mi%2Fb C19_STATE=coll:collection1 core:collection1 props:{shard=null, roles=null, state=down, core=collection1, collection=collection1, node_name=127.0.0.1:49828_mi%2Fb, base_url=http://127.0.0.1:49828/mi/b}
[junit4:junit4]   2> 23539 T533 C19 P49828 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 23555 T533 C19 P49828 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 23555 T531 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 23555 T533 C19 P49828 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 23555 T533 C19 P49828 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 23555 T444 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 23555 T444 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 23555 T444 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 23555 T533 C19 P49828 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 23968 T444 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 23968 T444 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49838
[junit4:junit4]   2> 23968 T444 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 23968 T444 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 23968 T444 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-1360580584937
[junit4:junit4]   2> 23968 T444 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1360580584937\solr.xml
[junit4:junit4]   2> 23968 T444 oasc.CoreContainer.<init> New CoreContainer 1692038
[junit4:junit4]   2> 23968 T444 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-1360580584937\'
[junit4:junit4]   2> 23968 T444 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-1360580584937\'
[junit4:junit4]   2> 24034 T444 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 60000
[junit4:junit4]   2> 24034 T444 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 24034 T444 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 24034 T444 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 24034 T444 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 24034 T444 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 24034 T444 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 24034 T444 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 24034 T444 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 24034 T444 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=60000&connTimeout=15000&retry=false
[junit4:junit4]   2> 24067 T444 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 24100 T444 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:49782/solr
[junit4:junit4]   2> 24100 T444 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 24100 T444 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49782 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@10e4b63
[junit4:junit4]   2> 24117 T444 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 24117 T543 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:49782. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 24117 T543 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:49782, initiating session
[junit4:junit4]   2> 24117 T446 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:49843
[junit4:junit4]   2> 24117 T446 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:49843
[junit4:junit4]   2> 24117 T448 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cc8ebc9e6000d with negotiated timeout 20000 for client /127.0.0.1:49843
[junit4:junit4]   2> 24117 T543 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:49782, sessionid = 0x13cc8ebc9e6000d, negotiated timeout = 20000
[junit4:junit4]   2> 24133 T544 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10e4b63 name:ZooKeeperConnection Watcher:127.0.0.1:49782 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 24133 T444 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 24133 T449 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cc8ebc9e6000d
[junit4:junit4]   2> 24133 T446 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:49843 which had sessionid 0x13cc8ebc9e6000d
[junit4:junit4]   2> 24133 T544 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 24133 T444 oaz.ZooKeeper.close Session: 0x13cc8ebc9e6000d closed
[junit4:junit4]   2> 24133 T444 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=60000&connTimeout=15000
[junit4:junit4]   2> 24150 T444 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49782/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@188e58c
[junit4:junit4]   2> 24150 T444 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 24150 T545 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:49782. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 24150 T545 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:49782, initiating session
[junit4:junit4]   2> 24150 T446 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:49846
[junit4:junit4]   2> 24150 T446 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:49846
[junit4:junit4]   2> 24150 T448 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cc8ebc9e6000e with negotiated timeout 20000 for client /127.0.0.1:49846
[junit4:junit4]   2> 24150 T545 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:49782, sessionid = 0x13cc8ebc9e6000e, negotiated timeout = 20000
[junit4:junit4]   2> 24150 T546 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@188e58c name:ZooKeeperConnection Watcher:127.0.0.1:49782/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 24150 T444 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 24150 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e6000e type:create cxid:0x1 zxid:0xc4 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 24150 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e6000e type:create cxid:0x2 zxid:0xc5 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 24166 T444 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 24166 T444 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49838_mi%2Fb
[junit4:junit4]   2> 24166 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e6000e type:delete cxid:0x9 zxid:0xc6 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:49838_mi%2Fb Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:49838_mi%2Fb
[junit4:junit4]   2> 24166 T444 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49838_mi%2Fb
[junit4:junit4]   2> 24183 T515 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> 24183 T500 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> 24183 T485 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4]   2> 24183 T485 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> 24183 T530 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4]   2> 24183 T530 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> 24183 T546 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4]   2> 24183 T472 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4]   2> 24183 T472 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> 24183 T466 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4]   2> 24183 T466 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> 24199 T515 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4]   2> 24199 T500 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4]   2> 24216 T547 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-1360580584937\collection1
[junit4:junit4]   2> 24216 T547 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 24216 T547 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 24216 T547 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 24216 T547 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-1360580584937\collection1\'
[junit4:junit4]   2> 24216 T547 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-1360580584937/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 24216 T547 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-1360580584937/collection1/lib/README' to classloader
[junit4:junit4]   2> 24298 T547 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4]   2> 24463 T547 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 24463 T547 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 24463 T547 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 24975 T467 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 24975 T467 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"3",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"recovering",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:49828_mi%2Fb",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:49828/mi/b"}
[junit4:junit4]   2> 24992 T530 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> 24992 T466 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> 24992 T485 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> 24992 T472 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> 24992 T515 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> 24992 T500 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> 24992 T546 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> 25603 T547 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 25619 T547 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 25619 T547 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 25652 T547 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 25652 T547 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 25669 T547 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 25669 T547 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 25685 T547 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-1360580584937\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365/jetty5\
[junit4:junit4]   2> 25685 T547 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1b4b8fc
[junit4:junit4]   2> 25685 T547 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4]   2> 25685 T547 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-1360580561365\jetty5 forceNew:false
[junit4:junit4]   2> 25685 T547 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\jetty5
[junit4:junit4]   2> 25685 T547 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365/jetty5\index/
[junit4:junit4]   2> 25685 T547 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\jetty5\index' doesn't exist. Creating new index...
[junit4:junit4]   2> 25685 T547 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-1360580561365\jetty5\index forceNew:false
[junit4:junit4]   2> 25702 T547 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(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-1360580561365\jetty5\index lockFactory=org.apache.lucene.store.NativeFSLockFactory@8d298e),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 25702 T547 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 25702 T547 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\jetty5\index
[junit4:junit4]   2> 25702 T547 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 25702 T547 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 25702 T547 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 25702 T547 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 25702 T547 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 25702 T547 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 25702 T547 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 25702 T547 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 25702 T547 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 25702 T547 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 25702 T547 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 25702 T547 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 25702 T547 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 25702 T547 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 25702 T547 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 25702 T547 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 25702 T547 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 25702 T547 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 25702 T547 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 25702 T547 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 25702 T547 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 25718 T547 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 25718 T547 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 25718 T547 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 25718 T547 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 25718 T547 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 25718 T547 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 25735 T547 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 25735 T547 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 25735 T547 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [SCHEMA.XML, OLD_SYNONYMS.TXT, STOPWORDS.TXT, PROTWORDS.TXT, OPEN-EXCHANGE-RATES.JSON, SYNONYMS.TXT, CURRENCY.XML, MAPPING-ISOLATIN1ACCENT.TXT]
[junit4:junit4]   2> 25751 T547 oasc.CachingDirectoryFactory.close Releasing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\jetty5
[junit4:junit4]   2> 25751 T547 oass.SolrIndexSearcher.<init> Opening Searcher@1cdb950 main
[junit4:junit4]   2> 25751 T547 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 25751 T547 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 25751 T547 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 25768 T547 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 25850 T548 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1cdb950 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 25850 T547 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 25850 T547 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 26626 T467 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 26626 T467 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "numShards":"3",
[junit4:junit4]   2> 	  "shard":null,
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"down",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:49838_mi%2Fb",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:49838/mi/b"}
[junit4:junit4]   2> 26626 T467 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4]   2> 26626 T467 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard2
[junit4:junit4]   2> 26643 T530 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> 26643 T515 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> 26643 T472 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> 26643 T500 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> 26643 T546 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> 26643 T466 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> 26643 T485 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> 26923 T547 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 26923 T547 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49838/mi/b collection:collection1 shard:shard2
[junit4:junit4]   2> 26923 T547 oasc.ZkController.register We are http://127.0.0.1:49838/mi/b/collection1/ and leader is http://127.0.0.1:49810/mi/b/collection1/
[junit4:junit4]   2> 26923 T547 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49838/mi/b
[junit4:junit4]   2> 26923 T547 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 26923 T547 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C20 name=collection1 org.apache.solr.core.SolrCore@15d9e71 url=http://127.0.0.1:49838/mi/b/collection1 node=127.0.0.1:49838_mi%2Fb C20_STATE=coll:collection1 core:collection1 props:{shard=null, roles=null, state=down, core=collection1, collection=collection1, node_name=127.0.0.1:49838_mi%2Fb, base_url=http://127.0.0.1:49838/mi/b}
[junit4:junit4]   2> 26923 T549 C20 P49838 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 26923 T549 C20 P49838 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 26923 T547 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 26923 T549 C20 P49838 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 26923 T549 C20 P49838 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 26923 T444 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4]   2> 26923 T444 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 26940 T549 C20 P49838 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 26940 T444 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 27386 T444 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 27386 T444 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49848
[junit4:junit4]   2> 27402 T444 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 27402 T444 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 27402 T444 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-1360580588305
[junit4:junit4]   2> 27402 T444 oasc.CoreContainer$Initializer.initialize looking for solr.xml: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1360580588305\solr.xml
[junit4:junit4]   2> 27402 T444 oasc.CoreContainer.<init> New CoreContainer 14794122
[junit4:junit4]   2> 27402 T444 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-1360580588305\'
[junit4:junit4]   2> 27402 T444 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-1360580588305\'
[junit4:junit4]   2> 27485 T444 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 60000
[junit4:junit4]   2> 27485 T444 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 27485 T444 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 27485 T444 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 27485 T444 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 27485 T444 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 27485 T444 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 27485 T444 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 27485 T444 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 27485 T444 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=60000&connTimeout=15000&retry=false
[junit4:junit4]   2> 27501 T444 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 27534 T444 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:49782/solr
[junit4:junit4]   2> 27534 T444 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 27534 T444 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49782 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@8ec961
[junit4:junit4]   2> 27534 T444 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 27534 T559 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:49782. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 27534 T559 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:49782, initiating session
[junit4:junit4]   2> 27534 T446 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:49853
[junit4:junit4]   2> 27534 T446 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:49853
[junit4:junit4]   2> 27551 T448 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cc8ebc9e6000f with negotiated timeout 20000 for client /127.0.0.1:49853
[junit4:junit4]   2> 27551 T559 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:49782, sessionid = 0x13cc8ebc9e6000f, negotiated timeout = 20000
[junit4:junit4]   2> 27567 T560 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8ec961 name:ZooKeeperConnection Watcher:127.0.0.1:49782 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 27567 T444 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 27567 T449 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13cc8ebc9e6000f
[junit4:junit4]   2> 27567 T444 oaz.ZooKeeper.close Session: 0x13cc8ebc9e6000f closed
[junit4:junit4]   2> 27567 T560 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 27567 T446 oazs.NIOServerCnxn.closeSock Closed socket connection for client /127.0.0.1:49853 which had sessionid 0x13cc8ebc9e6000f
[junit4:junit4]   2> 27567 T444 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=60000&connTimeout=15000
[junit4:junit4]   2> 27567 T444 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:49782/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@76827
[junit4:junit4]   2> 27567 T444 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 27567 T561 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server 127.0.0.1/127.0.0.1:49782. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 27567 T561 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to 127.0.0.1/127.0.0.1:49782, initiating session
[junit4:junit4]   2> 27567 T446 oazs.NIOServerCnxnFactory.run Accepted socket connection from /127.0.0.1:49856
[junit4:junit4]   2> 27567 T446 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /127.0.0.1:49856
[junit4:junit4]   2> 27600 T448 oazs.ZooKeeperServer.finishSessionInit Established session 0x13cc8ebc9e60010 with negotiated timeout 20000 for client /127.0.0.1:49856
[junit4:junit4]   2> 27600 T561 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server 127.0.0.1/127.0.0.1:49782, sessionid = 0x13cc8ebc9e60010, negotiated timeout = 20000
[junit4:junit4]   2> 27600 T562 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@76827 name:ZooKeeperConnection Watcher:127.0.0.1:49782/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 27600 T444 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 27617 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60010 type:create cxid:0x1 zxid:0xd7 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 27633 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60010 type:create cxid:0x2 zxid:0xd8 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 27683 T444 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 27683 T444 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49848_mi%2Fb
[junit4:junit4]   2> 27683 T449 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13cc8ebc9e60010 type:delete cxid:0x9 zxid:0xd9 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:49848_mi%2Fb Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:49848_mi%2Fb
[junit4:junit4]   2> 27683 T444 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49848_mi%2Fb
[junit4:junit4]   2> 27699 T500 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> 27699 T515 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> 27699 T562 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4]   2> 27699 T466 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4]   2> 27699 T466 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> 27699 T472 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4]   2> 27699 T472 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes 

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

16436 T444 oasc.CachingDirectoryFactory.close Closing directory when closing factory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\jetty12\index.20130211200524402
[junit4:junit4]   2> 516437 T444 oasc.CachingDirectoryFactory.closeDirectory Closing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\jetty12\index.20130211200524402
[junit4:junit4]   2> 516437 T444 oasc.CachingDirectoryFactory.close Closing directory when closing factory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\jetty12
[junit4:junit4]   2> 516437 T444 oasc.CachingDirectoryFactory.closeDirectory Closing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\jetty12
[junit4:junit4]   2> 516438 T444 oasc.CachingDirectoryFactory.close Closing directory when closing factory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\jetty12\index
[junit4:junit4]   2> 516438 T444 oasc.CachingDirectoryFactory.closeDirectory Closing directory:C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1360580561365\jetty12\index
[junit4:junit4]   2> 516992 T444 oaz.ZooKeeper.close Session: 0x13cc8ebc9e60022 closed
[junit4:junit4]   2> 516993 T789 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 517004 T444 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/mi/b,null}
[junit4:junit4]   2> 518336 T444 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4]   1> client port:0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=ChaosMonkeySafeLeaderTest -Dtests.method=testDistribSearch -Dtests.seed=1B84F2779348E815 -Dtests.slow=true -Dtests.locale=ar_SD -Dtests.timezone=ROK -Dtests.file.encoding=Cp1252
[junit4:junit4] FAILURE  518s | ChaosMonkeySafeLeaderTest.testDistribSearch <<<
[junit4:junit4]    > Throwable #1: java.lang.AssertionError: document count mismatch.  control=1259 sum(shards)=1260 cloudClient=1260
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([1B84F2779348E815:9A627C6FE4178829]:0)
[junit4:junit4]    > 	at org.junit.Assert.fail(Assert.java:93)
[junit4:junit4]    > 	at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1042)
[junit4:junit4]    > 	at org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.doTest(ChaosMonkeySafeLeaderTest.java:131)
[junit4:junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:794)
[junit4:junit4]    > 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4:junit4]    > 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4:junit4]    > 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4:junit4]    > 	at java.lang.reflect.Method.invoke(Method.java:601)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[junit4:junit4]    > 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]    > 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]    > 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 518410 T444 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4]   2> NOTE: test params are: codec=Appending, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=ar_SD, timezone=ROK
[junit4:junit4]   2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.7.0_10 (32-bit)/cpus=2,threads=2,free=61800792,total=99352576
[junit4:junit4]   2> NOTE: All tests run in this JVM: [BasicDistributedZk2Test, RequestHandlersTest, TestFaceting, TestFastOutputStream, HardAutoCommitTest, PingRequestHandlerTest, SpellingQueryConverterTest, DistributedQueryElevationComponentTest, ResponseLogComponentTest, TestComponentsName, TestOmitPositions, QueryParsingTest, URLClassifyProcessorTest, SchemaVersionSpecificBehaviorTest, ZkCLITest, TestSuggestSpellingConverter, ChaosMonkeySafeLeaderTest]
[junit4:junit4] Completed in 518.47s, 1 test, 1 failure <<< FAILURES!

[...truncated 729 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:381: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:361: 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:183: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\common-build.xml:447: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1202: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:865: There were test failures: 251 suites, 1043 tests, 1 failure, 13 ignored (8 assumptions)

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



Mime
View raw message