You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/06/16 15:30:54 UTC
[JENKINS] Lucene-Solr-trunk-Windows (64bit/jdk1.7.0_21) - Build #
2935 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/2935/
Java: 64bit/jdk1.7.0_21 -XX:+UseCompressedOops -XX:+UseG1GC
2 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.testDistribSearch
Error Message:
shard3 is not consistent. Got 680 from http://127.0.0.1:53869/d_lee/aj/collection1lastClient and got 677 from http://127.0.0.1:53902/d_lee/aj/collection1
Stack Trace:
java.lang.AssertionError: shard3 is not consistent. Got 680 from http://127.0.0.1:53869/d_lee/aj/collection1lastClient and got 677 from http://127.0.0.1:53902/d_lee/aj/collection1
at __randomizedtesting.SeedInfo.seed([176F19EC1E13F23C:968997F4694C9200]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:963)
at org.apache.solr.cloud.ChaosMonkeySafeLeaderTest.doTest(ChaosMonkeySafeLeaderTest.java:137)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
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)
REGRESSION: org.apache.solr.cloud.ChaosMonkeyShardSplitTest.testDistribSearch
Error Message:
Server at http://127.0.0.1:55578 returned non ok status:500, message:Server Error
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:55578 returned non ok status:500, message:Server Error
at __randomizedtesting.SeedInfo.seed([176F19EC1E13F23C:968997F4694C9200]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.cloud.ShardSplitTest.splitShard(ShardSplitTest.java:228)
at org.apache.solr.cloud.ChaosMonkeyShardSplitTest.doTest(ChaosMonkeyShardSplitTest.java:136)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
at sun.reflect.GeneratedMethodAccessor48.invoke(Unknown Source)
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 9629 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.ChaosMonkeySafeLeaderTest
[junit4:junit4] 2> 1329767 T3938 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /d_lee/aj
[junit4:junit4] 2> 1329773 T3938 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-ChaosMonkeySafeLeaderTest-1371387871542
[junit4:junit4] 2> 1329775 T3938 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 1329778 T3939 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 1329879 T3938 oasc.ZkTestServer.run start zk server on port:53763
[junit4:junit4] 2> 1329882 T3938 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1329893 T3945 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@24cdbdfc name:ZooKeeperConnection Watcher:127.0.0.1:53763 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1329894 T3938 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1329894 T3938 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 1329909 T3938 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1329914 T3947 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15cc3ad9 name:ZooKeeperConnection Watcher:127.0.0.1:53763/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1329915 T3938 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1329915 T3938 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 1329925 T3938 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 1329933 T3938 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 1329939 T3938 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 1329947 T3938 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 1329948 T3938 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 1329961 T3938 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 1329962 T3938 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 1329970 T3938 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 1329972 T3938 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 1329979 T3938 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 1329980 T3938 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 1329988 T3938 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 1329988 T3938 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 1329996 T3938 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 1329997 T3938 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 1330005 T3938 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 1330005 T3938 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 1330015 T3938 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 1330015 T3938 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 1330023 T3938 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 1330024 T3938 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 1330571 T3938 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1330580 T3938 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53770
[junit4:junit4] 2> 1330582 T3938 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1330582 T3938 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1330583 T3938 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1371387871804
[junit4:junit4] 2> 1330584 T3938 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1371387871804\solr.xml
[junit4:junit4] 2> 1330585 T3938 oasc.CoreContainer.<init> New CoreContainer 1230022088
[junit4:junit4] 2> 1330586 T3938 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1371387871804\'
[junit4:junit4] 2> 1330586 T3938 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1371387871804\'
[junit4:junit4] 2> 1330733 T3938 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1330734 T3938 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1330735 T3938 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1330735 T3938 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1330736 T3938 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1330736 T3938 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1330736 T3938 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1330737 T3938 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1330737 T3938 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1330737 T3938 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1330747 T3938 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1330748 T3938 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53763/solr
[junit4:junit4] 2> 1330748 T3938 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1330752 T3938 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1330767 T3958 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3adb753d name:ZooKeeperConnection Watcher:127.0.0.1:53763 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1330768 T3938 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1330774 T3938 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1330781 T3940 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13f4d1641400002, 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> 1330782 T3938 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1330793 T3960 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c76820c name:ZooKeeperConnection Watcher:127.0.0.1:53763/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1330793 T3938 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1330799 T3938 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 1330808 T3938 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 1330815 T3938 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 1330819 T3938 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53770_d_lee%2Faj
[junit4:junit4] 2> 1330823 T3938 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53770_d_lee%2Faj
[junit4:junit4] 2> 1330831 T3938 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 1330843 T3938 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 1330849 T3938 oasc.Overseer.start Overseer (id=89875275550031875-127.0.0.1:53770_d_lee%2Faj-n_0000000000) starting
[junit4:junit4] 2> 1330858 T3938 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 1330868 T3962 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 1330869 T3938 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 1330875 T3938 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 1330879 T3938 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1330885 T3961 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 1330892 T3963 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1330892 T3963 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1332392 T3961 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1332393 T3961 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:53770_d_lee%2Faj",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53770/d_lee/aj"}
[junit4:junit4] 2> 1332393 T3961 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 1332394 T3961 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 1332411 T3960 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> 1332895 T3963 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1371387871804\collection1
[junit4:junit4] 2> 1332895 T3963 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 1332897 T3963 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1332897 T3963 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 1332902 T3963 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1371387871804\collection1\'
[junit4:junit4] 2> 1332906 T3963 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1371387871804/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1332907 T3963 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1371387871804/collection1/lib/README' to classloader
[junit4:junit4] 2> 1333003 T3963 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 1333112 T3963 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1333115 T3963 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1333123 T3963 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 1334069 T3963 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1334081 T3963 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1334086 T3963 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1334114 T3963 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1334120 T3963 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1334126 T3963 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1334130 T3963 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1334130 T3963 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1334131 T3963 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1334133 T3963 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1334133 T3963 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1334134 T3963 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 1334134 T3963 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-controljetty-1371387871804\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541/control/data\
[junit4:junit4] 2> 1334134 T3963 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@753728e8
[junit4:junit4] 2> 1334134 T3963 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 1334137 T3963 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\control\data
[junit4:junit4] 2> 1334137 T3963 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541/control/data\index/
[junit4:junit4] 2> 1334139 T3963 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\control\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1334140 T3963 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\control\data\index
[junit4:junit4] 2> 1334154 T3963 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\control\data\index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 1334154 T3963 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1334158 T3963 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1334159 T3963 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1334160 T3963 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1334160 T3963 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1334161 T3963 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1334161 T3963 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1334162 T3963 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1334162 T3963 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1334163 T3963 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1334175 T3963 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1334191 T3963 oass.SolrIndexSearcher.<init> Opening Searcher@7140f0b0 main
[junit4:junit4] 2> 1334195 T3963 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1334195 T3963 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1334201 T3964 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7140f0b0 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1334202 T3963 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1334203 T3963 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53770/d_lee/aj collection:control_collection shard:shard1
[junit4:junit4] 2> 1334204 T3963 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 1334226 T3963 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 1334234 T3963 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 1334234 T3963 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 1334234 T3963 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53770/d_lee/aj/collection1/
[junit4:junit4] 2> 1334236 T3963 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 1334236 T3963 oasc.SyncStrategy.syncToMe http://127.0.0.1:53770/d_lee/aj/collection1/ has no replicas
[junit4:junit4] 2> 1334236 T3963 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53770/d_lee/aj/collection1/
[junit4:junit4] 2> 1334236 T3963 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 1335424 T3961 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1335448 T3960 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> 1335472 T3963 oasc.ZkController.register We are http://127.0.0.1:53770/d_lee/aj/collection1/ and leader is http://127.0.0.1:53770/d_lee/aj/collection1/
[junit4:junit4] 2> 1335472 T3963 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53770/d_lee/aj
[junit4:junit4] 2> 1335472 T3963 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 1335473 T3963 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 1335473 T3963 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1335478 T3963 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1335481 T3938 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 1335482 T3938 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1335483 T3938 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1335497 T3938 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 1335502 T3938 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1335507 T3967 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2e7c212a name:ZooKeeperConnection Watcher:127.0.0.1:53763/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1335508 T3938 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1335512 T3938 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1335518 T3938 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 1336132 T3938 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1336138 T3938 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53782
[junit4:junit4] 2> 1336138 T3938 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1336139 T3938 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1336140 T3938 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1371387877285
[junit4:junit4] 2> 1336140 T3938 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1371387877285\solr.xml
[junit4:junit4] 2> 1336141 T3938 oasc.CoreContainer.<init> New CoreContainer 1295318655
[junit4:junit4] 2> 1336142 T3938 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1371387877285\'
[junit4:junit4] 2> 1336143 T3938 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1371387877285\'
[junit4:junit4] 2> 1336275 T3938 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1336275 T3938 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1336276 T3938 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1336276 T3938 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1336276 T3938 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1336277 T3938 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1336277 T3938 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1336278 T3938 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1336279 T3938 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1336279 T3938 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1336287 T3938 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1336288 T3938 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53763/solr
[junit4:junit4] 2> 1336288 T3938 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1336291 T3938 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1336308 T3978 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@74f5ffdf name:ZooKeeperConnection Watcher:127.0.0.1:53763 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1336309 T3938 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1336324 T3940 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13f4d1641400005, 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> 1336324 T3938 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1336333 T3938 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1336338 T3980 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2470547a name:ZooKeeperConnection Watcher:127.0.0.1:53763/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1336338 T3938 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1336349 T3938 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1336960 T3961 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1336961 T3961 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:53770_d_lee%2Faj",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53770/d_lee/aj"}
[junit4:junit4] 2> 1336977 T3967 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> 1336978 T3960 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> 1336978 T3980 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> 1337315 T3938 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53782_d_lee%2Faj
[junit4:junit4] 2> 1337318 T3938 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53782_d_lee%2Faj
[junit4:junit4] 2> 1337324 T3960 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 1337325 T3980 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 1337325 T3967 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 1337325 T3967 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> 1337328 T3960 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 1337329 T3980 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 1337337 T3981 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1337337 T3981 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1338338 T3961 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1338339 T3961 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:53782_d_lee%2Faj",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53782/d_lee/aj"}
[junit4:junit4] 2> 1338339 T3961 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 3
[junit4:junit4] 2> 1338339 T3961 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 1338352 T3967 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> 1338353 T3980 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> 1338353 T3960 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> 1339139 T3981 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1371387877285\collection1
[junit4:junit4] 2> 1339139 T3981 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 1339141 T3981 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1339141 T3981 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 1339146 T3981 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1371387877285\collection1\'
[junit4:junit4] 2> 1339149 T3981 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1371387877285/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1339150 T3981 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1371387877285/collection1/lib/README' to classloader
[junit4:junit4] 2> 1339229 T3981 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 1339314 T3981 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1339316 T3981 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1339324 T3981 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 1340025 T3981 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1340035 T3981 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1340039 T3981 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1340060 T3981 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1340068 T3981 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1340076 T3981 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1340078 T3981 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1340078 T3981 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1340079 T3981 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1340081 T3981 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1340081 T3981 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1340081 T3981 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 1340082 T3981 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty1-1371387877285\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541/jetty1\
[junit4:junit4] 2> 1340082 T3981 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@753728e8
[junit4:junit4] 2> 1340082 T3981 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 1340084 T3981 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty1
[junit4:junit4] 2> 1340084 T3981 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541/jetty1\index/
[junit4:junit4] 2> 1340086 T3981 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty1\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1340086 T3981 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty1\index
[junit4:junit4] 2> 1340097 T3981 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty1\index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 1340097 T3981 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1340101 T3981 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1340101 T3981 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1340102 T3981 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1340103 T3981 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1340104 T3981 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1340104 T3981 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1340104 T3981 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1340104 T3981 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1340104 T3981 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1340114 T3981 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1340126 T3981 oass.SolrIndexSearcher.<init> Opening Searcher@7ae13c20 main
[junit4:junit4] 2> 1340127 T3981 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1340127 T3981 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1340134 T3982 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7ae13c20 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1340136 T3981 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1340136 T3981 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53782/d_lee/aj collection:collection1 shard:shard1
[junit4:junit4] 2> 1340138 T3981 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 1340157 T3981 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 1340164 T3981 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 1340164 T3981 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 1340164 T3981 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53782/d_lee/aj/collection1/
[junit4:junit4] 2> 1340165 T3981 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 1340165 T3981 oasc.SyncStrategy.syncToMe http://127.0.0.1:53782/d_lee/aj/collection1/ has no replicas
[junit4:junit4] 2> 1340165 T3981 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53782/d_lee/aj/collection1/
[junit4:junit4] 2> 1340165 T3981 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 1341062 T3961 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1341088 T3967 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> 1341089 T3960 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> 1341089 T3980 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> 1341097 T3981 oasc.ZkController.register We are http://127.0.0.1:53782/d_lee/aj/collection1/ and leader is http://127.0.0.1:53782/d_lee/aj/collection1/
[junit4:junit4] 2> 1341097 T3981 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53782/d_lee/aj
[junit4:junit4] 2> 1341098 T3981 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 1341099 T3981 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 1341099 T3981 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1341103 T3981 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1341106 T3938 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 1341107 T3938 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1341108 T3938 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1341578 T3938 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1341583 T3938 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53791
[junit4:junit4] 2> 1341584 T3938 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1341585 T3938 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1341585 T3938 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1371387882886
[junit4:junit4] 2> 1341586 T3938 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1371387882886\solr.xml
[junit4:junit4] 2> 1341587 T3938 oasc.CoreContainer.<init> New CoreContainer 660636215
[junit4:junit4] 2> 1341588 T3938 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1371387882886\'
[junit4:junit4] 2> 1341588 T3938 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1371387882886\'
[junit4:junit4] 2> 1341704 T3938 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1341704 T3938 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1341705 T3938 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1341705 T3938 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1341705 T3938 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1341705 T3938 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1341707 T3938 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1341707 T3938 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1341707 T3938 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1341708 T3938 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1341715 T3938 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1341716 T3938 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53763/solr
[junit4:junit4] 2> 1341716 T3938 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1341718 T3938 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1341733 T3994 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1661adff name:ZooKeeperConnection Watcher:127.0.0.1:53763 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1341734 T3938 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1341740 T3938 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1341740 T3940 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13f4d1641400007, 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> 1341747 T3938 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1341752 T3996 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@366ed66b name:ZooKeeperConnection Watcher:127.0.0.1:53763/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1341752 T3938 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1341762 T3938 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1342453 T3961 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1342454 T3961 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:53782_d_lee%2Faj",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53782/d_lee/aj"}
[junit4:junit4] 2> 1342468 T3967 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> 1342469 T3996 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> 1342469 T3980 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> 1342469 T3960 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> 1342668 T3938 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53791_d_lee%2Faj
[junit4:junit4] 2> 1342672 T3938 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53791_d_lee%2Faj
[junit4:junit4] 2> 1342677 T3960 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> 1342679 T3967 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 1342679 T3967 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> 1342681 T3996 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 1342681 T3996 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> 1342677 T3980 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> 1342687 T3960 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 1342689 T3980 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 1342696 T3997 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1342696 T3997 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1343832 T3961 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1343833 T3961 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:53791_d_lee%2Faj",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53791/d_lee/aj"}
[junit4:junit4] 2> 1343833 T3961 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 1343833 T3961 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 1343848 T3967 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> 1343849 T3996 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> 1343849 T3980 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> 1343849 T3960 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> 1344498 T3997 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1371387882886\collection1
[junit4:junit4] 2> 1344498 T3997 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 1344500 T3997 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1344500 T3997 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 1344505 T3997 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1371387882886\collection1\'
[junit4:junit4] 2> 1344508 T3997 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1371387882886/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1344508 T3997 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1371387882886/collection1/lib/README' to classloader
[junit4:junit4] 2> 1344569 T3997 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 1344632 T3997 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1344635 T3997 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1344642 T3997 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 1345309 T3997 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1345322 T3997 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1345326 T3997 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1345352 T3997 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1345359 T3997 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1345368 T3997 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1345371 T3997 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1345372 T3997 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1345372 T3997 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1345374 T3997 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1345374 T3997 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1345375 T3997 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 1345375 T3997 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty2-1371387882886\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541/jetty2\
[junit4:junit4] 2> 1345375 T3997 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@753728e8
[junit4:junit4] 2> 1345377 T3997 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 1345378 T3997 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty2
[junit4:junit4] 2> 1345380 T3997 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541/jetty2\index/
[junit4:junit4] 2> 1345382 T3997 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty2\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1345382 T3997 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty2\index
[junit4:junit4] 2> 1345398 T3997 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty2\index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 1345398 T3997 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1345400 T3997 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1345402 T3997 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1345402 T3997 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1345402 T3997 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1345403 T3997 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1345403 T3997 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1345403 T3997 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1345405 T3997 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1345405 T3997 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1345419 T3997 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1345434 T3997 oass.SolrIndexSearcher.<init> Opening Searcher@5d6d3f4a main
[junit4:junit4] 2> 1345438 T3997 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1345438 T3997 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1345445 T3998 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5d6d3f4a main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1345447 T3997 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1345448 T3997 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53791/d_lee/aj collection:collection1 shard:shard2
[junit4:junit4] 2> 1345450 T3997 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 1345467 T3997 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 1345477 T3997 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 1345477 T3997 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 1345478 T3997 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53791/d_lee/aj/collection1/
[junit4:junit4] 2> 1345478 T3997 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 1345478 T3997 oasc.SyncStrategy.syncToMe http://127.0.0.1:53791/d_lee/aj/collection1/ has no replicas
[junit4:junit4] 2> 1345478 T3997 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53791/d_lee/aj/collection1/
[junit4:junit4] 2> 1345478 T3997 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 1346623 T3961 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1346646 T3960 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> 1346646 T3996 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> 1346647 T3980 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> 1346647 T3967 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> 1346655 T3997 oasc.ZkController.register We are http://127.0.0.1:53791/d_lee/aj/collection1/ and leader is http://127.0.0.1:53791/d_lee/aj/collection1/
[junit4:junit4] 2> 1346655 T3997 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53791/d_lee/aj
[junit4:junit4] 2> 1346656 T3997 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 1346657 T3997 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 1346657 T3997 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1346662 T3997 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1346664 T3938 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 1346665 T3938 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1346665 T3938 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1347245 T3938 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1347251 T3938 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53800
[junit4:junit4] 2> 1347252 T3938 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1347252 T3938 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1347253 T3938 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1371387888454
[junit4:junit4] 2> 1347254 T3938 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1371387888454\solr.xml
[junit4:junit4] 2> 1347254 T3938 oasc.CoreContainer.<init> New CoreContainer 1348265277
[junit4:junit4] 2> 1347256 T3938 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1371387888454\'
[junit4:junit4] 2> 1347256 T3938 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1371387888454\'
[junit4:junit4] 2> 1347419 T3938 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1347420 T3938 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1347420 T3938 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1347421 T3938 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1347422 T3938 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1347422 T3938 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1347423 T3938 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1347424 T3938 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1347424 T3938 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1347425 T3938 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1347437 T3938 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1347438 T3938 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53763/solr
[junit4:junit4] 2> 1347439 T3938 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1347442 T3938 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1347462 T4010 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@25c65f03 name:ZooKeeperConnection Watcher:127.0.0.1:53763 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1347463 T3938 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1347475 T3940 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13f4d1641400009, 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> 1347475 T3938 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1347488 T3938 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1347494 T4012 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2ef9c4e2 name:ZooKeeperConnection Watcher:127.0.0.1:53763/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1347496 T3938 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1347515 T3938 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1348149 T3961 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1348151 T3961 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:53791_d_lee%2Faj",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53791/d_lee/aj"}
[junit4:junit4] 2> 1348161 T3960 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> 1348161 T4012 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> 1348163 T3996 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> 1348163 T3967 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> 1348163 T3980 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> 1348511 T3938 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53800_d_lee%2Faj
[junit4:junit4] 2> 1348520 T3938 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53800_d_lee%2Faj
[junit4:junit4] 2> 1348530 T4012 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> 1348531 T3980 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> 1348532 T3960 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> 1348535 T3996 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1348536 T3996 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> 1348538 T3967 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1348538 T3967 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> 1348540 T4012 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1348541 T3980 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1348542 T3960 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1348553 T4013 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1348554 T4013 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1349659 T3961 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1349660 T3961 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"4",
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:53800_d_lee%2Faj",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53800/d_lee/aj"}
[junit4:junit4] 2> 1349660 T3961 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 1349661 T3961 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard3
[junit4:junit4] 2> 1349674 T3967 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> 1349675 T3996 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> 1349675 T4012 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> 1349675 T3980 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> 1349675 T3960 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> 1350536 T4013 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1371387888454\collection1
[junit4:junit4] 2> 1350536 T4013 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 1350538 T4013 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1350538 T4013 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 1350543 T4013 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1371387888454\collection1\'
[junit4:junit4] 2> 1350545 T4013 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1371387888454/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1350547 T4013 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1371387888454/collection1/lib/README' to classloader
[junit4:junit4] 2> 1350612 T4013 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 1350717 T4013 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1350720 T4013 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1350725 T4013 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 1351445 T4013 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1351456 T4013 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1351460 T4013 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1351483 T4013 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1351489 T4013 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1351497 T4013 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1351499 T4013 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1351499 T4013 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1351500 T4013 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1351502 T4013 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1351502 T4013 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1351502 T4013 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 1351503 T4013 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty3-1371387888454\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541/jetty3\
[junit4:junit4] 2> 1351503 T4013 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@753728e8
[junit4:junit4] 2> 1351504 T4013 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 1351505 T4013 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty3
[junit4:junit4] 2> 1351506 T4013 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541/jetty3\index/
[junit4:junit4] 2> 1351507 T4013 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty3\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1351508 T4013 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty3\index
[junit4:junit4] 2> 1351518 T4013 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty3\index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 1351518 T4013 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1351522 T4013 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1351522 T4013 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1351523 T4013 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1351524 T4013 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1351525 T4013 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1351525 T4013 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1351525 T4013 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1351526 T4013 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1351527 T4013 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1351538 T4013 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1351549 T4013 oass.SolrIndexSearcher.<init> Opening Searcher@376e88f0 main
[junit4:junit4] 2> 1351550 T4013 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1351550 T4013 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1351557 T4014 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@376e88f0 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1351559 T4013 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1351559 T4013 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53800/d_lee/aj collection:collection1 shard:shard3
[junit4:junit4] 2> 1351561 T4013 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard3/election
[junit4:junit4] 2> 1351576 T4013 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 1351584 T4013 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 1351584 T4013 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 1351584 T4013 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:53800/d_lee/aj/collection1/
[junit4:junit4] 2> 1351585 T4013 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 1351586 T4013 oasc.SyncStrategy.syncToMe http://127.0.0.1:53800/d_lee/aj/collection1/ has no replicas
[junit4:junit4] 2> 1351586 T4013 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:53800/d_lee/aj/collection1/
[junit4:junit4] 2> 1351586 T4013 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard3
[junit4:junit4] 2> 1352659 T3961 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1352682 T3960 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> 1352683 T3980 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> 1352683 T3967 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> 1352683 T3996 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> 1352683 T4012 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> 1352708 T4013 oasc.ZkController.register We are http://127.0.0.1:53800/d_lee/aj/collection1/ and leader is http://127.0.0.1:53800/d_lee/aj/collection1/
[junit4:junit4] 2> 1352708 T4013 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53800/d_lee/aj
[junit4:junit4] 2> 1352708 T4013 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 1352708 T4013 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 1352708 T4013 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1352712 T4013 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1352714 T3938 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 1352715 T3938 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1352715 T3938 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1353118 T3938 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1353123 T3938 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53809
[junit4:junit4] 2> 1353124 T3938 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1353124 T3938 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1353125 T3938 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1371387894490
[junit4:junit4] 2> 1353125 T3938 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1371387894490\solr.xml
[junit4:junit4] 2> 1353126 T3938 oasc.CoreContainer.<init> New CoreContainer 1437958672
[junit4:junit4] 2> 1353126 T3938 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1371387894490\'
[junit4:junit4] 2> 1353127 T3938 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1371387894490\'
[junit4:junit4] 2> 1353235 T3938 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1353236 T3938 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1353236 T3938 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1353236 T3938 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1353237 T3938 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1353237 T3938 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1353237 T3938 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1353238 T3938 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1353238 T3938 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1353239 T3938 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1353245 T3938 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1353246 T3938 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53763/solr
[junit4:junit4] 2> 1353246 T3938 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1353248 T3938 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1353264 T4026 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2b69685a name:ZooKeeperConnection Watcher:127.0.0.1:53763 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1353265 T3938 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1353271 T3938 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1353277 T3938 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1353281 T4028 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6ecb5439 name:ZooKeeperConnection Watcher:127.0.0.1:53763/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1353282 T3938 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1353290 T3938 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1354186 T3961 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1354188 T3961 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"4",
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":"shard3",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:53800_d_lee%2Faj",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53800/d_lee/aj"}
[junit4:junit4] 2> 1354228 T3967 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> 1354230 T3980 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> 1354231 T4028 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> 1354230 T4012 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> 1354229 T3960 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> 1354233 T3996 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> 1354285 T3938 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53809_d_lee%2Faj
[junit4:junit4] 2> 1354289 T3938 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53809_d_lee%2Faj
[junit4:junit4] 2> 1354295 T3960 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> 1354295 T4012 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> 1354296 T3980 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> 1354296 T4028 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> 1354301 T3996 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1354302 T3996 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> 1354303 T3967 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1354303 T3967 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> 1354305 T4012 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1354306 T3960 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1354307 T3980 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1354307 T4028 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1354319 T4029 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1354320 T4029 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1355730 T3961 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1355732 T3961 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"5",
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:53809_d_lee%2Faj",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53809/d_lee/aj"}
[junit4:junit4] 2> 1355732 T3961 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 1355732 T3961 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 1355746 T3967 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> 1355747 T4028 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> 1355747 T3996 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> 1355746 T3960 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> 1355747 T4012 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> 1355746 T3980 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> 1356347 T4029 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1371387894490\collection1
[junit4:junit4] 2> 1356347 T4029 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 1356350 T4029 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1356350 T4029 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 1356352 T4029 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1371387894490\collection1\'
[junit4:junit4] 2> 1356354 T4029 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1371387894490/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1356355 T4029 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1371387894490/collection1/lib/README' to classloader
[junit4:junit4] 2> 1356423 T4029 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 1356499 T4029 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1356504 T4029 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1356510 T4029 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 1357343 T4029 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1357356 T4029 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1357362 T4029 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1357391 T4029 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1357399 T4029 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1357407 T4029 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1357411 T4029 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1357411 T4029 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1357411 T4029 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1357413 T4029 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1357413 T4029 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1357413 T4029 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 1357414 T4029 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty4-1371387894490\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541/jetty4\
[junit4:junit4] 2> 1357414 T4029 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@753728e8
[junit4:junit4] 2> 1357415 T4029 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 1357416 T4029 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty4
[junit4:junit4] 2> 1357416 T4029 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541/jetty4\index/
[junit4:junit4] 2> 1357418 T4029 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty4\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1357418 T4029 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty4\index
[junit4:junit4] 2> 1357433 T4029 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty4\index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 1357433 T4029 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1357437 T4029 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1357437 T4029 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1357437 T4029 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1357439 T4029 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1357440 T4029 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1357440 T4029 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1357440 T4029 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1357441 T4029 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1357441 T4029 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1357452 T4029 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1357464 T4029 oass.SolrIndexSearcher.<init> Opening Searcher@681a881d main
[junit4:junit4] 2> 1357467 T4029 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1357467 T4029 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1357473 T4030 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@681a881d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1357476 T4029 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1357476 T4029 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53809/d_lee/aj collection:collection1 shard:shard1
[junit4:junit4] 2> 1357486 T4029 oasc.ZkController.register We are http://127.0.0.1:53809/d_lee/aj/collection1/ and leader is http://127.0.0.1:53782/d_lee/aj/collection1/
[junit4:junit4] 2> 1357487 T4029 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53809/d_lee/aj
[junit4:junit4] 2> 1357487 T4029 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 1357488 T4029 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C891 name=collection1 org.apache.solr.core.SolrCore@534ac21a url=http://127.0.0.1:53809/d_lee/aj/collection1 node=127.0.0.1:53809_d_lee%2Faj C891_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:53809_d_lee%2Faj, base_url=http://127.0.0.1:53809/d_lee/aj}
[junit4:junit4] 2> 1357489 T4031 C891 P53809 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 1357489 T4031 C891 P53809 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 1357490 T4031 C891 P53809 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 1357490 T4031 C891 P53809 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1357490 T4029 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1357493 T4031 C891 P53809 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1357495 T3938 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 1357495 T3938 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1357496 T3938 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1357504 T3971 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 1357995 T3938 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1358000 T3938 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53819
[junit4:junit4] 2> 1358001 T3938 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1358001 T3938 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1358001 T3938 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1371387899269
[junit4:junit4] 2> 1358003 T3938 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1371387899269\solr.xml
[junit4:junit4] 2> 1358003 T3938 oasc.CoreContainer.<init> New CoreContainer 1533149232
[junit4:junit4] 2> 1358004 T3938 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1371387899269\'
[junit4:junit4] 2> 1358004 T3938 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1371387899269\'
[junit4:junit4] 2> 1358143 T3938 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1358144 T3938 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1358144 T3938 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1358144 T3938 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1358145 T3938 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1358146 T3938 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1358147 T3938 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1358147 T3938 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1358148 T3938 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1358148 T3938 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1358162 T3938 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1358164 T3938 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53763/solr
[junit4:junit4] 2> 1358164 T3938 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1358167 T3938 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1358187 T4043 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@288ab2bd name:ZooKeeperConnection Watcher:127.0.0.1:53763 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1358188 T3938 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1358193 T3938 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1358205 T3938 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1358209 T4045 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3ec46006 name:ZooKeeperConnection Watcher:127.0.0.1:53763/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1358210 T3938 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1358222 T3938 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1359018 T3961 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1359019 T3961 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"5",
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:53809_d_lee%2Faj",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53809/d_lee/aj"}
[junit4:junit4] 2> 1359037 T3967 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> 1359038 T3980 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> 1359039 T3996 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> 1359040 T4028 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> 1359039 T4045 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> 1359038 T3960 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> 1359040 T4012 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> 1359318 T3938 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53819_d_lee%2Faj
[junit4:junit4] 2> 1359323 T3938 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53819_d_lee%2Faj
[junit4:junit4] 2> 1359331 T3967 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 1359332 T3967 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> 1359332 T4012 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> 1359333 T4045 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 1359333 T4045 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> 1359331 T4028 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> 1359331 T3960 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> 1359336 T3996 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 1359336 T3996 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> 1359331 T3980 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> 1359343 T4012 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 1359344 T4028 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 1359344 T3960 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 1359346 T3980 oascc.ZkStateReader$3.process Updating live nodes... (6)
[junit4:junit4] 2> 1359355 T4046 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1359356 T4046 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1359682 T3971 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 1359682 T3971 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=5&state=recovering&nodeName=127.0.0.1:53809_d_lee%252Faj&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2178
[junit4:junit4] 2> 1360691 T3961 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1360693 T3961 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"6",
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:53819_d_lee%2Faj",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53819/d_lee/aj"}
[junit4:junit4] 2> 1360693 T3961 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 1360694 T3961 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 1360711 T3967 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> 1360713 T3980 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> 1360714 T4028 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> 1360713 T4012 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> 1360713 T3960 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> 1360714 T3996 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> 1360713 T4045 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> 1361536 T4046 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1371387899269\collection1
[junit4:junit4] 2> 1361536 T4046 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 1361538 T4046 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1361538 T4046 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 1361541 T4046 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1371387899269\collection1\'
[junit4:junit4] 2> 1361543 T4046 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1371387899269/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1361544 T4046 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1371387899269/collection1/lib/README' to classloader
[junit4:junit4] 2> 1361604 T4046 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 1361683 T4046 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1361686 T4046 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1361692 T4046 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> C891_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:53809_d_lee%2Faj, base_url=http://127.0.0.1:53809/d_lee/aj}
[junit4:junit4] 2> 1361861 T4031 C891 P53809 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:53782/d_lee/aj/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 1361861 T4031 C891 P53809 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:53809/d_lee/aj START replicas=[http://127.0.0.1:53782/d_lee/aj/collection1/] nUpdates=100
[junit4:junit4] 2> 1361862 T4031 C891 P53809 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 1361863 T4031 C891 P53809 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 1361863 T4031 C891 P53809 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 1361863 T4031 C891 P53809 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 1361864 T4031 C891 P53809 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 1361864 T4031 C891 P53809 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:53782/d_lee/aj/collection1/. core=collection1
[junit4:junit4] 2> 1361865 T4031 C891 P53809 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C892 name=collection1 org.apache.solr.core.SolrCore@623c8b7d url=http://127.0.0.1:53782/d_lee/aj/collection1 node=127.0.0.1:53782_d_lee%2Faj C892_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:53782_d_lee%2Faj, base_url=http://127.0.0.1:53782/d_lee/aj, leader=true}
[junit4:junit4] 2> 1361872 T3972 C892 P53782 oasc.SolrCore.execute [collection1] webapp=/d_lee/aj path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 2> 1361875 T3973 C892 P53782 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1361887 T3973 C892 P53782 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty1\index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 1361888 T3973 C892 P53782 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1361902 T3973 C892 P53782 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty1\index,segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty1\index,segFN=segments_2,generation=2}
[junit4:junit4] 2> 1361902 T3973 C892 P53782 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1361909 T3973 C892 P53782 oass.SolrIndexSearcher.<init> Opening Searcher@32f940de realtime
[junit4:junit4] 2> 1361909 T3973 C892 P53782 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1361909 T3973 C892 P53782 oasup.LogUpdateProcessor.finish [collection1] webapp=/d_lee/aj path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 34
[junit4:junit4] 2> 1361911 T4031 C891 P53809 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 1361911 T4031 C891 P53809 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 1361915 T3974 C892 P53782 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 1361916 T3974 C892 P53782 oasc.SolrCore.execute [collection1] webapp=/d_lee/aj path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=2
[junit4:junit4] 2> 1361917 T4031 C891 P53809 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 1361917 T4031 C891 P53809 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 1361917 T4031 C891 P53809 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 1361921 T3975 C892 P53782 oasc.SolrCore.execute [collection1] webapp=/d_lee/aj path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=1
[junit4:junit4] 2> 1361922 T4031 C891 P53809 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 1361926 T4031 C891 P53809 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty4\index.20130616130503690
[junit4:junit4] 2> 1361928 T4031 C891 P53809 oash.SnapPuller.fetchLatestIndex Starting download to org.apache.lucene.store.MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty4\index.20130616130503690 lockFactory=org.apache.lucene.store.NativeFSLockFactory@de08f9c fullCopy=false
[junit4:junit4] 2> 1361932 T3976 C892 P53782 oasc.SolrCore.execute [collection1] webapp=/d_lee/aj path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 1361934 T4031 C891 P53809 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 1361940 T4031 C891 P53809 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 1361940 T4031 C891 P53809 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 1361950 T4031 C891 P53809 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty4\index,segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty4\index,segFN=segments_2,generation=2}
[junit4:junit4] 2> 1361950 T4031 C891 P53809 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1361951 T4031 C891 P53809 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 1361953 T4031 C891 P53809 oass.SolrIndexSearcher.<init> Opening Searcher@1ea477c1 main
[junit4:junit4] 2> 1361954 T4030 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1ea477c1 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1361955 T4031 C891 P53809 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty4\index.20130616130503690 [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty4\index.20130616130503690;done=true>>]
[junit4:junit4] 2> 1361955 T4031 C891 P53809 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty4\index.20130616130503690
[junit4:junit4] 2> 1361955 T4031 C891 P53809 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty4\index.20130616130503690
[junit4:junit4] 2> 1361956 T4031 C891 P53809 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 1361956 T4031 C891 P53809 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 1361957 T4031 C891 P53809 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 1361957 T4031 C891 P53809 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1361963 T4031 C891 P53809 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 1362362 T3961 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1362364 T3961 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"5",
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:53809_d_lee%2Faj",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53809/d_lee/aj"}
[junit4:junit4] 2> 1362381 T3960 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> 1362381 T4012 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> 1362381 T3980 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> 1362382 T3996 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> 1362382 T4028 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> 1362383 T3967 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> 1362383 T4045 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> 1362503 T4046 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1362517 T4046 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1362521 T4046 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1362550 T4046 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1362567 T4046 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1362574 T4046 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1362577 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1362577 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1362577 T4046 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1362579 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1362579 T4046 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1362579 T4046 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 1362580 T4046 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty5-1371387899269\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541/jetty5\
[junit4:junit4] 2> 1362580 T4046 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@753728e8
[junit4:junit4] 2> 1362581 T4046 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 1362583 T4046 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty5
[junit4:junit4] 2> 1362584 T4046 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541/jetty5\index/
[junit4:junit4] 2> 1362585 T4046 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty5\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1362586 T4046 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty5\index
[junit4:junit4] 2> 1362596 T4046 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty5\index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 1362596 T4046 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1362601 T4046 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1362602 T4046 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1362602 T4046 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1362603 T4046 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1362604 T4046 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1362604 T4046 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1362610 T4046 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1362611 T4046 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1362611 T4046 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1362623 T4046 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1362637 T4046 oass.SolrIndexSearcher.<init> Opening Searcher@5dea1dc5 main
[junit4:junit4] 2> 1362640 T4046 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1362640 T4046 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1362646 T4049 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5dea1dc5 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1362648 T4046 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1362650 T4046 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53819/d_lee/aj collection:collection1 shard:shard2
[junit4:junit4] 2> 1362657 T4046 oasc.ZkController.register We are http://127.0.0.1:53819/d_lee/aj/collection1/ and leader is http://127.0.0.1:53791/d_lee/aj/collection1/
[junit4:junit4] 2> 1362657 T4046 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53819/d_lee/aj
[junit4:junit4] 2> 1362657 T4046 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 1362657 T4046 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C893 name=collection1 org.apache.solr.core.SolrCore@39d6ef96 url=http://127.0.0.1:53819/d_lee/aj/collection1 node=127.0.0.1:53819_d_lee%2Faj C893_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:53819_d_lee%2Faj, base_url=http://127.0.0.1:53819/d_lee/aj}
[junit4:junit4] 2> 1362658 T4050 C893 P53819 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 1362658 T4050 C893 P53819 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 1362659 T4050 C893 P53819 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 1362659 T4050 C893 P53819 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1362659 T4046 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1362663 T4050 C893 P53819 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1362665 T3938 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 1362667 T3938 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1362668 T3938 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1362681 T3990 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 6, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 1363106 T3938 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1363110 T3938 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53832
[junit4:junit4] 2> 1363110 T3938 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1363111 T3938 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1363111 T3938 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1371387904444
[junit4:junit4] 2> 1363111 T3938 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1371387904444\solr.xml
[junit4:junit4] 2> 1363113 T3938 oasc.CoreContainer.<init> New CoreContainer 627296458
[junit4:junit4] 2> 1363113 T3938 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1371387904444\'
[junit4:junit4] 2> 1363113 T3938 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1371387904444\'
[junit4:junit4] 2> 1363234 T3938 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1363235 T3938 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1363235 T3938 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1363235 T3938 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1363235 T3938 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1363236 T3938 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1363236 T3938 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1363237 T3938 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1363238 T3938 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1363238 T3938 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1363247 T3938 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1363247 T3938 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53763/solr
[junit4:junit4] 2> 1363248 T3938 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1363250 T3938 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1363271 T4062 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@44b289ef name:ZooKeeperConnection Watcher:127.0.0.1:53763 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1363271 T3938 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1363277 T3938 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1363285 T3938 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1363290 T4064 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5875929f name:ZooKeeperConnection Watcher:127.0.0.1:53763/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1363290 T3938 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1363300 T3938 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1364032 T3961 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1364034 T3961 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"6",
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:53819_d_lee%2Faj",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53819/d_lee/aj"}
[junit4:junit4] 2> 1364046 T3967 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> 1364049 T3980 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> 1364050 T4064 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> 1364049 T4045 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> 1364049 T4012 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> 1364049 T3960 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> 1364052 T3996 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> 1364052 T4028 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> 1364394 T3938 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53832_d_lee%2Faj
[junit4:junit4] 2> 1364404 T3938 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53832_d_lee%2Faj
[junit4:junit4] 2> 1364410 T3960 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> 1364410 T3980 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> 1364411 T4028 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> 1364411 T4012 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> 1364413 T3967 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 1364413 T3967 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> 1364415 T4045 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 1364415 T4045 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> 1364415 T4064 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 1364415 T4064 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> 1364416 T3996 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 1364416 T3996 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> 1364424 T3960 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 1364424 T3980 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 1364425 T4028 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 1364426 T4012 oascc.ZkStateReader$3.process Updating live nodes... (7)
[junit4:junit4] 2> 1364438 T4065 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1364438 T4065 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1364860 T3990 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 6, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 1364860 T3990 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=6&state=recovering&nodeName=127.0.0.1:53819_d_lee%252Faj&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2179
[junit4:junit4] 2> 1365704 T3961 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1365705 T3961 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"7",
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:53832_d_lee%2Faj",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53832/d_lee/aj"}
[junit4:junit4] 2> 1365705 T3961 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=3
[junit4:junit4] 2> 1365705 T3961 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard3
[junit4:junit4] 2> 1365719 T3960 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 1365720 T3980 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 1365720 T4028 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 1365721 T3996 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 1365721 T4012 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 1365722 T4064 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 1365722 T4045 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 1365722 T3967 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 1366618 T4065 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1371387904444\collection1
[junit4:junit4] 2> 1366618 T4065 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 1366620 T4065 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1366621 T4065 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 1366624 T4065 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1371387904444\collection1\'
[junit4:junit4] 2> 1366628 T4065 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1371387904444/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1366629 T4065 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1371387904444/collection1/lib/README' to classloader
[junit4:junit4] 2> 1366699 T4065 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 1366767 T4065 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1366770 T4065 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1366776 T4065 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> C893_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:53819_d_lee%2Faj, base_url=http://127.0.0.1:53819/d_lee/aj}
[junit4:junit4] 2> 1367008 T4050 C893 P53819 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:53791/d_lee/aj/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 1367008 T4050 C893 P53819 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:53819/d_lee/aj START replicas=[http://127.0.0.1:53791/d_lee/aj/collection1/] nUpdates=100
[junit4:junit4] 2> 1367009 T4050 C893 P53819 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 1367009 T4050 C893 P53819 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 1367009 T4050 C893 P53819 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 1367009 T4050 C893 P53819 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 1367009 T4050 C893 P53819 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 1367009 T4050 C893 P53819 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:53791/d_lee/aj/collection1/. core=collection1
[junit4:junit4] 2> 1367010 T4050 C893 P53819 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C894 name=collection1 org.apache.solr.core.SolrCore@6b55ac12 url=http://127.0.0.1:53791/d_lee/aj/collection1 node=127.0.0.1:53791_d_lee%2Faj C894_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:53791_d_lee%2Faj, base_url=http://127.0.0.1:53791/d_lee/aj, leader=true}
[junit4:junit4] 2> 1367023 T3991 C894 P53791 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1367027 T3992 C894 P53791 oasc.SolrCore.execute [collection1] webapp=/d_lee/aj path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 2> 1367034 T3991 C894 P53791 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty2\index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 1367035 T3991 C894 P53791 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1367042 T3991 C894 P53791 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty2\index,segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty2\index,segFN=segments_2,generation=2}
[junit4:junit4] 2> 1367043 T3991 C894 P53791 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1367046 T3991 C894 P53791 oass.SolrIndexSearcher.<init> Opening Searcher@2e84543 realtime
[junit4:junit4] 2> 1367047 T3991 C894 P53791 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1367047 T3991 C894 P53791 oasup.LogUpdateProcessor.finish [collection1] webapp=/d_lee/aj path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 24
[junit4:junit4] 2> 1367049 T4050 C893 P53819 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 1367049 T4050 C893 P53819 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 1367054 T3987 C894 P53791 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 1367055 T3987 C894 P53791 oasc.SolrCore.execute [collection1] webapp=/d_lee/aj path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=2
[junit4:junit4] 2> 1367056 T4050 C893 P53819 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 1367056 T4050 C893 P53819 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 1367056 T4050 C893 P53819 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 1367062 T3988 C894 P53791 oasc.SolrCore.execute [collection1] webapp=/d_lee/aj path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=3
[junit4:junit4] 2> 1367062 T4050 C893 P53819 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 1367064 T4050 C893 P53819 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty5\index.20130616130508830
[junit4:junit4] 2> 1367065 T4050 C893 P53819 oash.SnapPuller.fetchLatestIndex Starting download to org.apache.lucene.store.MMapDirectory@C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty5\index.20130616130508830 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1f30b411 fullCopy=false
[junit4:junit4] 2> 1367069 T3989 C894 P53791 oasc.SolrCore.execute [collection1] webapp=/d_lee/aj path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 1367072 T4050 C893 P53819 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 1367079 T4050 C893 P53819 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 1367079 T4050 C893 P53819 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 1367086 T4050 C893 P53819 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty5\index,segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty5\index,segFN=segments_2,generation=2}
[junit4:junit4] 2> 1367086 T4050 C893 P53819 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1367087 T4050 C893 P53819 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 1367088 T4050 C893 P53819 oass.SolrIndexSearcher.<init> Opening Searcher@52213a68 main
[junit4:junit4] 2> 1367089 T4049 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@52213a68 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1367090 T4050 C893 P53819 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty5\index.20130616130508830 [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty5\index.20130616130508830;done=true>>]
[junit4:junit4] 2> 1367090 T4050 C893 P53819 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty5\index.20130616130508830
[junit4:junit4] 2> 1367090 T4050 C893 P53819 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty5\index.20130616130508830
[junit4:junit4] 2> 1367092 T4050 C893 P53819 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 1367092 T4050 C893 P53819 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 1367092 T4050 C893 P53819 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 1367092 T4050 C893 P53819 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1367095 T4050 C893 P53819 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 1367311 T3961 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1367314 T3961 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=3 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"6",
[junit4:junit4] 2> "numShards":"3",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:53819_d_lee%2Faj",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53819/d_lee/aj"}
[junit4:junit4] 2> 1367328 T3960 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 1367329 T4012 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 1367329 T3980 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 1367330 T4064 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 1367330 T4028 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 1367331 T3996 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 1367331 T3967 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 1367332 T4045 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 7)
[junit4:junit4] 2> 1367597 T4065 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1367611 T4065 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1367615 T4065 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1367635 T4065 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1367648 T4065 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1367654 T4065 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1367656 T4065 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1367656 T4065 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1367657 T4065 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1367658 T4065 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1367658 T4065 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 1367659 T4065 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 1367660 T4065 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty6-1371387904444\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541/jetty6\
[junit4:junit4] 2> 1367660 T4065 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@753728e8
[junit4:junit4] 2> 1367660 T4065 oasc.SolrCore.initDirectoryFactory solr.StandardDirectoryFactory
[junit4:junit4] 2> 1367661 T4065 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty6
[junit4:junit4] 2> 1367662 T4065 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541/jetty6\index/
[junit4:junit4] 2> 1367663 T4065 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty6\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1367663 T4065 oasc.CachingDirectoryFactory.get return new directory for C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty6\index
[junit4:junit4] 2> 1367672 T4065 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-1371387871541\jetty6\index,segFN=segments_1,generation=1}
[junit4:junit4] 2> 1367672 T4065 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1367677 T4065 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1367677 T4065 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1367678 T4065 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1367678 T4065 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1367679 T4065 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1367679 T4065 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1367684 T4065 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1367685 T4065 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1367685 T4065 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1367695 T4065 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1367706 T4065 oass.SolrIndexSearcher.<init> Opening Searcher@4d05668d main
[junit4:junit4] 2> 1367708 T4065 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1367708 T4065 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1367716 T4068 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4d05668d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1367719 T4065 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1367719 T4065 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53832/d_lee/aj collection:collection1 shard:shard3
[junit4:junit4] 2> 1367727 T4065 oasc.ZkController.register We are http://127.0.0.1:53832/d_lee/aj/collection1/ and leader is http://127.0.0.1:53800/d_lee/aj/collection1/
[junit4:junit4] 2> 1367728 T4065 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53832/d_lee/aj
[junit4:junit4] 2> 1367728 T4065 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 1367728 T4065 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C895 name=collection1 org.apache.solr.core.SolrCore@ecee44a url=http://127.0.0.1:53832/d_lee/aj/collection1 node=127.0.0.1:53832_d_lee%2Faj C895_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:53832_d_lee%2Faj, base_url=http://127.0.0.1:53832/d_lee/aj}
[junit4:junit4] 2> 1367732 T4069 C895 P53832 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 1367732 T4069 C895 P53832 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 1367732 T4069 C895 P53832 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 1367733 T4069 C895 P53832 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1367733 T4065 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1367737 T4069 C895 P53832 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1367739 T3938 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 1367739 T3938 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1367740 T3938 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1367747 T4004 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 7, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 1368176 T3938 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1368182 T3938 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:53845
[junit4:junit4] 2> 1368183 T3938 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1368184 T3938 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1368185 T3938 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1371387909514
[junit4:junit4] 2> 1368185 T3938 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1371387909514\solr.xml
[junit4:junit4] 2> 1368186 T3938 oasc.CoreContainer.<init> New CoreContainer 527826612
[junit4:junit4] 2> 1368187 T3938 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1371387909514\'
[junit4:junit4] 2> 1368188 T3938 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeySafeLeaderTest-jetty7-1371387909514\'
[junit4:junit4] 2> 1368304 T3938 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1368304 T3938 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1368304 T3938 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1368305 T3938 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1368305 T3938 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1368305 T3938 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1368306 T3938 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1368306 T3938 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1368307 T3938 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1368307 T3938 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1368315 T3938 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1368316 T3938 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:53763/solr
[junit4:junit4] 2> 1368316 T3938 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1368318 T3938 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1368333 T4081 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@58bf709a name:ZooKeeperConnection Watcher:127.0.0.1:53763 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1368333 T3938 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1368339 T3938 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000
[...truncated too long message...]
junit4:junit4] 2> 2735451 T7131 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 2735458 T7131 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:55559 55559
[junit4:junit4] 2> 2736741 T7222 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 2737934 T7222 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 2737936 T7131 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 55566
[junit4:junit4] 2> 2737956 T7131 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 2737957 T7131 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:55559 55559
[junit4:junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeyShardSplitTest -Dtests.method=testDistribSearch -Dtests.seed=176F19EC1E13F23C -Dtests.slow=true -Dtests.locale=es_PA -Dtests.timezone=America/Moncton -Dtests.file.encoding=US-ASCII
[junit4:junit4] ERROR 70.1s | ChaosMonkeyShardSplitTest.testDistribSearch <<<
[junit4:junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:55578 returned non ok status:500, message:Server Error
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([176F19EC1E13F23C:968997F4694C9200]:0)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4:junit4] > at org.apache.solr.cloud.ShardSplitTest.splitShard(ShardSplitTest.java:228)
[junit4:junit4] > at org.apache.solr.cloud.ChaosMonkeyShardSplitTest.doTest(ChaosMonkeyShardSplitTest.java:136)
[junit4:junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2> 2737963 T7131 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {id=Pulsing41(freqCutoff=11 minBlockSize=17 maxBlockSize=76), _version_=PostingsFormat(name=Lucene41WithOrds), n_ti=PostingsFormat(name=Lucene41WithOrds)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=es_PA, timezone=America/Moncton
[junit4:junit4] 2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.7.0_21 (64-bit)/cpus=2,threads=2,free=353060864,total=536870912
[junit4:junit4] 2> NOTE: All tests run in this JVM: [RegexBoostProcessorTest, TestDefaultSimilarityFactory, CSVRequestHandlerTest, TestPropInjectDefaults, PluginInfoTest, TestSolrCoreProperties, TestShardHandlerFactory, SolrRequestParserTest, NumericFieldsTest, TestBinaryResponseWriter, TestSort, SolrCoreTest, SuggesterFSTTest, IndexSchemaRuntimeFieldTest, ShardRoutingCustomTest, TermVectorComponentTest, FieldAnalysisRequestHandlerTest, SampleTest, SyncSliceTest, TestBadConfig, TestSystemIdResolver, MinimalSchemaTest, TestCoreDiscovery, BasicDistributedZkTest, CollectionsAPIDistributedZkTest, ChaosMonkeyNothingIsSafeTest, XsltUpdateRequestHandlerTest, TestLFUCache, LegacyHTMLStripCharFilterTest, IndexReaderFactoryTest, TestFunctionQuery, SimpleFacetsTest, TestDistributedGrouping, TestAnalyzedSuggestions, TestLMJelinekMercerSimilarityFactory, TestLuceneMatchVersion, SchemaVersionSpecificBehaviorTest, SpellingQueryConverterTest, DebugComponentTest, DistributedQueryElevationComponentTest, TestWriterPerf, TestMaxScoreQueryParser, XmlUpdateRequestHandlerTest, TestReversedWildcardFilterFactory, TestElisionMultitermQuery, TestIBSimilarityFactory, UpdateRequestProcessorFactoryTest, CachingDirectoryFactoryTest, TestPropInject, DocumentBuilderTest, SignatureUpdateProcessorFactoryTest, TimeZoneUtilsTest, UniqFieldsUpdateProcessorFactoryTest, TestGroupingSearch, QueryParsingTest, UpdateParamsTest, TestDistributedSearch, SpellCheckComponentTest, TestReload, TestQuerySenderNoQuery, TestCopyFieldCollectionResource, TestSolrQueryParserDefaultOperatorResource, TestSolrXMLSerializer, TestWordDelimiterFilterFactory, ResponseLogComponentTest, CoreContainerCoreInitFailuresTest, IndexSchemaTest, OverseerCollectionProcessorTest, TestCloudManagedSchemaAddField, DocumentAnalysisRequestHandlerTest, TestFieldTypeResource, AliasIntegrationTest, TestDFRSimilarityFactory, TestJmxIntegration, BadCopyFieldTest, TestQueryTypes, TestStressReorder, BasicDistributedZk2Test, SoftAutoCommitTest, TestSolrQueryParserResource, PathHierarchyTokenizerFactoryTest, TestFoldingMultitermQuery, NoCacheHeaderTest, TestSolrIndexConfig, TestSolrXml, AlternateDirectoryTest, SolrIndexConfigTest, TestTrie, DateMathParserTest, TestBinaryField, TestSolrQueryParser, TestPHPSerializedResponseWriter, JsonLoaderTest, ExternalFileFieldSortTest, RecoveryZkTest, NotRequiredUniqueKeyTest, StatelessScriptUpdateProcessorFactoryTest, TestFaceting, HardAutoCommitTest, PrimUtilsTest, TestUtils, IndexBasedSpellCheckerTest, FastVectorHighlighterTest, RAMDirectoryFactoryTest, TestJoin, TestReplicationHandler, TestRemoteStreaming, TestSolrDeletionPolicy2, TestSweetSpotSimilarityFactory, WordBreakSolrSpellCheckerTest, TestFastWriter, TestRandomFaceting, QueryElevationComponentTest, TestIndexingPerformance, TestUpdate, SolrCoreCheckLockOnStartupTest, SliceStateTest, TestSchemaVersionResource, RequestHandlersTest, ClusterStateTest, DateFieldTest, OpenExchangeRatesOrgProviderTest, DirectUpdateHandlerOptimizeTest, TestSchemaSimilarityResource, TestDynamicFieldCollectionResource, AutoCommitTest, TestDocumentBuilder, TestZkChroot, TestLRUCache, CoreAdminHandlerTest, TestSurroundQueryParser, TestLazyCores, CurrencyFieldOpenExchangeTest, BasicZkTest, TestPseudoReturnFields, DefaultValueUpdateProcessorTest, CopyFieldTest, TestHashPartitioner, TestJmxMonitoredMap, SolrPluginUtilsTest, ReturnFieldsTest, SolrCmdDistributorTest, ZkSolrClientTest, ChaosMonkeySafeLeaderTest, UnloadDistributedZkTest, OpenCloseCoreStressTest, OverseerTest, LeaderElectionIntegrationTest, ShardRoutingTest, FullSolrCloudDistribCmdsTest, ClusterStateUpdateTest, LeaderElectionTest, TestRandomDVFaceting, ZkCLITest, SliceStateUpdateTest, TestRecovery, DistributedSpellCheckComponentTest, TermVectorComponentDistributedTest, ZkControllerTest, TestRealTimeGet, TestMultiCoreConfBootstrap, TestStressVersions, DistributedTermsComponentTest, TestRangeQuery, TestCoreContainer, TestSolr4Spatial, StatsComponentTest, PeerSyncTest, BadIndexSchemaTest, ConvertedLegacyTest, TestFiltering, BasicFunctionalityTest, DirectUpdateHandlerTest, TestIndexSearcher, HighlighterTest, ShowFileRequestHandlerTest, CurrencyFieldXmlFileTest, SolrIndexSplitterTest, SimplePostToolTest, AnalysisAfterCoreReloadTest, TestExtendedDismaxParser, SpellCheckCollatorTest, DocValuesTest, SuggesterTSTTest, SuggesterTest, TestStressLucene, SpatialFilterTest, SuggesterWFSTTest, TestCSVLoader, PolyFieldTest, FieldMutatingUpdateProcessorTest, TestAtomicUpdateErrorCases, QueryEqualityTest, SortByFunctionTest, DocValuesMultiTest, DistanceFunctionTest, TestSolrDeletionPolicy1, SolrInfoMBeanTest, CacheHeaderTest, LukeRequestHandlerTest, DisMaxRequestHandlerTest, TestQueryUtils, StandardRequestHandlerTest, DirectSolrSpellCheckerTest, PrimitiveFieldTypeTest, TestOmitPositions, FileBasedSpellCheckerTest, TermsComponentTest, TestValueSourceCache, MoreLikeThisHandlerTest, RequiredFieldsTest, TestArbitraryIndexDir, LoggingHandlerTest, TestCollationField, JSONWriterTest, TestCSVResponseWriter, MBeansHandlerTest, BinaryUpdateRequestHandlerTest, TestPartialUpdateDeduplication, PingRequestHandlerTest, TestComponentsName, SearchHandlerTest, HighlighterConfigTest, SOLR749Test, TestQuerySenderListener, BadComponentTest, TestStressRecovery, TestMergePolicyConfig, MultiTermTest, TestDocSet, TestSearchPerf, TestConfig, OutputWriterTest, TestFuzzyAnalyzedSuggestions, TestPostingsSolrHighlighter, DirectSolrConnectionTest, TestPhraseSuggestions, SpellPossibilityIteratorTest, TestCharFilters, TestCodecSupport, SynonymTokenizerTest, TestXIncludeConfig, EchoParamsTest, TestPerFieldSimilarity, TestNumberUtils, TestLMDirichletSimilarityFactory, TestBM25SimilarityFactory, TestPluginEnable, ResourceLoaderTest, TestFastOutputStream, ScriptEngineTest, URLClassifyProcessorTest, TestFastLRUCache, PreAnalyzedFieldTest, TestSuggestSpellingConverter, DOMUtilTest, TestSolrJ, ZkNodePropsTest, SystemInfoHandlerTest, UUIDFieldTest, FileUtilsTest, CircularListTest, TestRTGBase, SolrTestCaseJ4Test, ChaosMonkeyShardSplitTest]
[junit4:junit4] Completed in 70.09s, 1 test, 1 error <<< FAILURES!
[...truncated 65 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:386: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:366: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:181: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:437: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1243: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:887: There were test failures: 296 suites, 1243 tests, 1 error, 1 failure, 18 ignored (12 assumptions)
Total time: 71 minutes 1 second
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_21 -XX:+UseCompressedOops -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure