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/15 08:59:28 UTC
[JENKINS] Lucene-Solr-4.x-Windows (32bit/jdk1.7.0_21) - Build #
2892 - Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/2892/
Java: 32bit/jdk1.7.0_21 -server -XX:+UseParallelGC
2 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeyShardSplitTest.testDistribSearch
Error Message:
Server at http://127.0.0.1:49904 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:49904 returned non ok status:500, message:Server Error
at __randomizedtesting.SeedInfo.seed([BEDDACF4B8103E18:3F3B22ECCF4F5E24]: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.GeneratedMethodAccessor46.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)
FAILED: org.apache.solr.cloud.RecoveryZkTest.testDistribSearch
Error Message:
expected:<193> but was:<41>
Stack Trace:
java.lang.AssertionError: expected:<193> but was:<41>
at __randomizedtesting.SeedInfo.seed([BEDDACF4B8103E18:3F3B22ECCF4F5E24]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.junit.Assert.assertEquals(Assert.java:456)
at org.apache.solr.cloud.RecoveryZkTest.doTest(RecoveryZkTest.java:108)
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)
Build Log:
[...truncated 9401 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.RecoveryZkTest
[junit4:junit4] 2> 895543 T2505 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /k_np/sf
[junit4:junit4] 2> 895547 T2505 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-RecoveryZkTest-1371277875140
[junit4:junit4] 2> 895549 T2505 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 895549 T2506 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 895636 T2505 oasc.ZkTestServer.run start zk server on port:63928
[junit4:junit4] 2> 895639 T2505 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 895655 T2512 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@19c1f18 name:ZooKeeperConnection Watcher:127.0.0.1:63928 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 895656 T2505 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 895656 T2505 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 895677 T2505 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 895684 T2514 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@acee16 name:ZooKeeperConnection Watcher:127.0.0.1:63928/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 895685 T2505 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 895685 T2505 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 895702 T2505 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 895713 T2505 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 895721 T2505 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 895734 T2505 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 895736 T2505 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 895748 T2505 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 895748 T2505 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 895753 T2505 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 895753 T2505 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 895758 T2505 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 895758 T2505 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 895764 T2505 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 895764 T2505 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 895768 T2505 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 895769 T2505 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 895774 T2505 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 895774 T2505 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 895778 T2505 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 895779 T2505 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 895783 T2505 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 895783 T2505 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 895789 T2507 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13f4687d7cd0001, 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> 896156 T2505 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 896161 T2505 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:63935
[junit4:junit4] 2> 896161 T2505 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 896161 T2505 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 896161 T2505 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1371277875382
[junit4:junit4] 2> 896162 T2505 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1371277875382\solr.xml
[junit4:junit4] 2> 896162 T2505 oasc.CoreContainer.<init> New CoreContainer 28941321
[junit4:junit4] 2> 896163 T2505 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1371277875382\'
[junit4:junit4] 2> 896163 T2505 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1371277875382\'
[junit4:junit4] 2> 896249 T2505 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 896250 T2505 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 896250 T2505 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 896250 T2505 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 896250 T2505 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 896250 T2505 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 896251 T2505 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 896251 T2505 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 896252 T2505 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 896252 T2505 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 896259 T2505 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 896260 T2505 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:63928/solr
[junit4:junit4] 2> 896260 T2505 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 896262 T2505 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 896276 T2525 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18914aa name:ZooKeeperConnection Watcher:127.0.0.1:63928 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 896277 T2505 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 896283 T2505 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 896284 T2507 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13f4687d7cd0002, 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> 896289 T2505 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 896292 T2527 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1552fc9 name:ZooKeeperConnection Watcher:127.0.0.1:63928/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 896293 T2505 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 896296 T2505 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 896303 T2505 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 896309 T2505 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 896312 T2505 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63935_k_np%2Fsf
[junit4:junit4] 2> 896315 T2505 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:63935_k_np%2Fsf
[junit4:junit4] 2> 896320 T2505 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 896329 T2505 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 896334 T2505 oasc.Overseer.start Overseer (id=89868066825764867-127.0.0.1:63935_k_np%2Fsf-n_0000000000) starting
[junit4:junit4] 2> 896341 T2505 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 896348 T2529 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 896349 T2505 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 896353 T2505 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 896356 T2505 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 896360 T2528 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 896365 T2530 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 896365 T2530 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 897667 T2528 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 897671 T2528 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:63935_k_np%2Fsf",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63935/k_np/sf"}
[junit4:junit4] 2> 897672 T2528 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 897673 T2528 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 897694 T2527 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> 898096 T2530 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1371277875382\collection1
[junit4:junit4] 2> 898096 T2530 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 898097 T2530 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 898098 T2530 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 898104 T2530 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1371277875382\collection1\'
[junit4:junit4] 2> 898108 T2530 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1371277875382/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 898110 T2530 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1371277875382/collection1/lib/README' to classloader
[junit4:junit4] 2> 898153 T2530 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 898204 T2530 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 898206 T2530 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 898215 T2530 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 898762 T2530 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 898770 T2530 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 898773 T2530 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 898790 T2530 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 898795 T2530 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 898801 T2530 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 898802 T2530 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 898802 T2530 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 898802 T2530 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 898804 T2530 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 898804 T2530 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 898804 T2530 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 898805 T2530 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1371277875382\collection1\, dataDir=.\org.apache.solr.cloud.RecoveryZkTest-1371277875140/control/data\
[junit4:junit4] 2> 898805 T2530 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@ab6cbb
[junit4:junit4] 2> 898805 T2530 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 898806 T2530 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.RecoveryZkTest-1371277875140/control/data\
[junit4:junit4] 2> 898806 T2530 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.RecoveryZkTest-1371277875140/control/data\index/
[junit4:junit4] 2> 898806 T2530 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.RecoveryZkTest-1371277875140\control\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 898806 T2530 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.RecoveryZkTest-1371277875140/control/data\index
[junit4:junit4] 2> 898811 T2530 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@f73246 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1ff9db0),segFN=segments_1,generation=1}
[junit4:junit4] 2> 898811 T2530 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 898813 T2530 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 898813 T2530 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 898814 T2530 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 898814 T2530 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 898815 T2530 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 898815 T2530 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 898815 T2530 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 898816 T2530 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 898816 T2530 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 898824 T2530 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 898829 T2530 oass.SolrIndexSearcher.<init> Opening Searcher@493d4a main
[junit4:junit4] 2> 898830 T2530 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.RecoveryZkTest-1371277875140\control\data\tlog
[junit4:junit4] 2> 898831 T2530 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 898831 T2530 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 898834 T2530 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 898834 T2530 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:63935/k_np/sf collection:control_collection shard:shard1
[junit4:junit4] 2> 898836 T2530 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 898841 T2531 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@493d4a main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 898852 T2530 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 898857 T2530 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 898857 T2530 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 898858 T2530 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:63935/k_np/sf/collection1/
[junit4:junit4] 2> 898858 T2530 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 898858 T2530 oasc.SyncStrategy.syncToMe http://127.0.0.1:63935/k_np/sf/collection1/ has no replicas
[junit4:junit4] 2> 898858 T2530 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:63935/k_np/sf/collection1/
[junit4:junit4] 2> 898858 T2530 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 899001 T2528 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 899014 T2527 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> 899044 T2530 oasc.ZkController.register We are http://127.0.0.1:63935/k_np/sf/collection1/ and leader is http://127.0.0.1:63935/k_np/sf/collection1/
[junit4:junit4] 2> 899044 T2530 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:63935/k_np/sf
[junit4:junit4] 2> 899044 T2530 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 899044 T2530 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 899044 T2530 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 899047 T2530 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 899049 T2505 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 899049 T2505 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 899050 T2505 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 899057 T2505 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 899059 T2505 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 899062 T2534 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b50725 name:ZooKeeperConnection Watcher:127.0.0.1:63928/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 899062 T2505 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 899065 T2505 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 899067 T2505 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 899440 T2505 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 899444 T2505 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:63947
[junit4:junit4] 2> 899445 T2505 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 899445 T2505 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 899445 T2505 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1371277878660
[junit4:junit4] 2> 899445 T2505 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1371277878660\solr.xml
[junit4:junit4] 2> 899446 T2505 oasc.CoreContainer.<init> New CoreContainer 887594
[junit4:junit4] 2> 899446 T2505 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1371277878660\'
[junit4:junit4] 2> 899446 T2505 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1371277878660\'
[junit4:junit4] 2> 899538 T2505 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 899538 T2505 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 899539 T2505 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 899539 T2505 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 899539 T2505 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 899539 T2505 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 899539 T2505 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 899540 T2505 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 899540 T2505 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 899541 T2505 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 899549 T2505 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 899549 T2505 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:63928/solr
[junit4:junit4] 2> 899549 T2505 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 899551 T2505 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 899567 T2545 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@ac81f7 name:ZooKeeperConnection Watcher:127.0.0.1:63928 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 899567 T2505 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 899574 T2505 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 899586 T2505 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 899589 T2547 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c0b88 name:ZooKeeperConnection Watcher:127.0.0.1:63928/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 899589 T2505 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 899598 T2505 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 900323 T2528 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 900324 T2528 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:63935_k_np%2Fsf_collection1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:63935_k_np%2Fsf",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63935/k_np/sf"}
[junit4:junit4] 2> 900352 T2534 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> 900353 T2547 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> 900355 T2527 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> 900466 T2505 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63947_k_np%2Fsf
[junit4:junit4] 2> 900469 T2505 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:63947_k_np%2Fsf
[junit4:junit4] 2> 900472 T2547 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> 900473 T2527 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> 900473 T2534 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 900473 T2534 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> 900476 T2547 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 900477 T2527 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 900485 T2548 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 900485 T2548 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 901560 T2528 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 901561 T2528 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:63947_k_np%2Fsf",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63947/k_np/sf"}
[junit4:junit4] 2> 901561 T2528 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 1
[junit4:junit4] 2> 901561 T2528 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 901571 T2534 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> 901571 T2547 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> 901571 T2527 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> 902054 T2548 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1371277878660\collection1
[junit4:junit4] 2> 902054 T2548 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 902055 T2548 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 902055 T2548 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 902057 T2548 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1371277878660\collection1\'
[junit4:junit4] 2> 902059 T2548 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1371277878660/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 902059 T2548 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1371277878660/collection1/lib/README' to classloader
[junit4:junit4] 2> 902099 T2548 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 902150 T2548 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 902152 T2548 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 902156 T2548 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 902665 T2548 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 902675 T2548 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 902678 T2548 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 902697 T2548 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 902702 T2548 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 902708 T2548 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 902709 T2548 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 902709 T2548 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 902710 T2548 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 902711 T2548 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 902711 T2548 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 902711 T2548 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 902712 T2548 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1371277878660\collection1\, dataDir=.\org.apache.solr.cloud.RecoveryZkTest-1371277875140/jetty1\
[junit4:junit4] 2> 902712 T2548 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@ab6cbb
[junit4:junit4] 2> 902713 T2548 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 902713 T2548 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.RecoveryZkTest-1371277875140/jetty1\
[junit4:junit4] 2> 902713 T2548 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.RecoveryZkTest-1371277875140/jetty1\index/
[junit4:junit4] 2> 902713 T2548 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.RecoveryZkTest-1371277875140\jetty1\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 902714 T2548 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.RecoveryZkTest-1371277875140/jetty1\index
[junit4:junit4] 2> 902717 T2548 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4a1f46 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6fa52d),segFN=segments_1,generation=1}
[junit4:junit4] 2> 902717 T2548 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 902721 T2548 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 902721 T2548 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 902721 T2548 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 902722 T2548 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 902723 T2548 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 902723 T2548 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 902723 T2548 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 902724 T2548 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 902724 T2548 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 902733 T2548 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 902739 T2548 oass.SolrIndexSearcher.<init> Opening Searcher@18dfb0 main
[junit4:junit4] 2> 902739 T2548 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.RecoveryZkTest-1371277875140\jetty1\tlog
[junit4:junit4] 2> 902742 T2548 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 902742 T2548 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 902748 T2549 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@18dfb0 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 902748 T2548 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 902748 T2548 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:63947/k_np/sf collection:collection1 shard:shard1
[junit4:junit4] 2> 902749 T2548 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 902767 T2548 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 902772 T2548 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 902772 T2548 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 902773 T2548 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:63947/k_np/sf/collection1/
[junit4:junit4] 2> 902773 T2548 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 902773 T2548 oasc.SyncStrategy.syncToMe http://127.0.0.1:63947/k_np/sf/collection1/ has no replicas
[junit4:junit4] 2> 902773 T2548 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:63947/k_np/sf/collection1/
[junit4:junit4] 2> 902774 T2548 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 903917 T2528 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 903970 T2527 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> 903971 T2547 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> 903970 T2534 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> 903978 T2548 oasc.ZkController.register We are http://127.0.0.1:63947/k_np/sf/collection1/ and leader is http://127.0.0.1:63947/k_np/sf/collection1/
[junit4:junit4] 2> 903979 T2548 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:63947/k_np/sf
[junit4:junit4] 2> 903979 T2548 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 903980 T2548 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 903980 T2548 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 903987 T2548 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 903993 T2505 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 903996 T2505 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 903996 T2505 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 904373 T2505 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 904376 T2505 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:63956
[junit4:junit4] 2> 904376 T2505 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 904376 T2505 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 904377 T2505 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1371277883601
[junit4:junit4] 2> 904377 T2505 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1371277883601\solr.xml
[junit4:junit4] 2> 904377 T2505 oasc.CoreContainer.<init> New CoreContainer 19697619
[junit4:junit4] 2> 904377 T2505 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1371277883601\'
[junit4:junit4] 2> 904379 T2505 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1371277883601\'
[junit4:junit4] 2> 904466 T2505 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 904466 T2505 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 904467 T2505 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 904467 T2505 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 904468 T2505 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 904468 T2505 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 904468 T2505 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 904468 T2505 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 904468 T2505 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 904468 T2505 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 904475 T2505 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 904475 T2505 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:63928/solr
[junit4:junit4] 2> 904476 T2505 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 904478 T2505 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 904490 T2561 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@455e5a name:ZooKeeperConnection Watcher:127.0.0.1:63928 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 904490 T2505 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 904494 T2505 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 904501 T2505 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 904506 T2563 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@167bf02 name:ZooKeeperConnection Watcher:127.0.0.1:63928/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 904506 T2505 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 904515 T2505 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 905163 T2528 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 905164 T2528 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:63947_k_np%2Fsf_collection1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:63947_k_np%2Fsf",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63947/k_np/sf"}
[junit4:junit4] 2> 905175 T2563 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> 905176 T2527 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> 905176 T2547 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> 905176 T2534 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> 905296 T2505 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63956_k_np%2Fsf
[junit4:junit4] 2> 905299 T2505 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:63956_k_np%2Fsf
[junit4:junit4] 2> 905302 T2527 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> 905302 T2547 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> 905303 T2563 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 905303 T2563 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> 905304 T2534 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 905304 T2534 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> 905307 T2527 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 905308 T2547 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 905316 T2564 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 905316 T2564 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 906354 T2528 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 906355 T2528 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:63956_k_np%2Fsf",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63956/k_np/sf"}
[junit4:junit4] 2> 906356 T2528 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4] 2> 906356 T2528 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 906373 T2563 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> 906373 T2527 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> 906373 T2534 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> 906373 T2547 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> 906874 T2564 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1371277883601\collection1
[junit4:junit4] 2> 906874 T2564 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 906876 T2564 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 906877 T2564 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 906882 T2564 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1371277883601\collection1\'
[junit4:junit4] 2> 906886 T2564 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1371277883601/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 906887 T2564 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1371277883601/collection1/lib/README' to classloader
[junit4:junit4] 2> 906929 T2564 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 906977 T2564 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 906980 T2564 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 906985 T2564 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 907486 T2564 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 907494 T2564 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 907497 T2564 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 907515 T2564 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 907519 T2564 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 907523 T2564 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 907525 T2564 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 907525 T2564 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 907526 T2564 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 907527 T2564 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 907528 T2564 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 907528 T2564 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 907528 T2564 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1371277883601\collection1\, dataDir=.\org.apache.solr.cloud.RecoveryZkTest-1371277875140/jetty2\
[junit4:junit4] 2> 907528 T2564 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@ab6cbb
[junit4:junit4] 2> 907528 T2564 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 907529 T2564 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.RecoveryZkTest-1371277875140/jetty2\
[junit4:junit4] 2> 907529 T2564 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.RecoveryZkTest-1371277875140/jetty2\index/
[junit4:junit4] 2> 907529 T2564 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.RecoveryZkTest-1371277875140\jetty2\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 907530 T2564 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.RecoveryZkTest-1371277875140/jetty2\index
[junit4:junit4] 2> 907534 T2564 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@a89caf lockFactory=org.apache.lucene.store.NativeFSLockFactory@14ed00a),segFN=segments_1,generation=1}
[junit4:junit4] 2> 907534 T2564 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 907538 T2564 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 907538 T2564 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 907538 T2564 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 907538 T2564 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 907539 T2564 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 907539 T2564 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 907540 T2564 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 907540 T2564 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 907541 T2564 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 907550 T2564 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 907557 T2564 oass.SolrIndexSearcher.<init> Opening Searcher@144da59 main
[junit4:junit4] 2> 907558 T2564 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.RecoveryZkTest-1371277875140\jetty2\tlog
[junit4:junit4] 2> 907560 T2564 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 907560 T2564 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 907563 T2565 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@144da59 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 907564 T2564 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 907565 T2564 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:63956/k_np/sf collection:collection1 shard:shard1
[junit4:junit4] 2> 907569 T2564 oasc.ZkController.register We are http://127.0.0.1:63956/k_np/sf/collection1/ and leader is http://127.0.0.1:63947/k_np/sf/collection1/
[junit4:junit4] 2> 907569 T2564 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:63956/k_np/sf
[junit4:junit4] 2> 907570 T2564 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 907570 T2564 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C927 name=collection1 org.apache.solr.core.SolrCore@16aa6e8 url=http://127.0.0.1:63956/k_np/sf/collection1 node=127.0.0.1:63956_k_np%2Fsf C927_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:63956_k_np%2Fsf, base_url=http://127.0.0.1:63956/k_np/sf}
[junit4:junit4] 2> 907570 T2566 C927 P63956 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 907571 T2564 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 907572 T2566 C927 P63956 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 907572 T2566 C927 P63956 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 907572 T2566 C927 P63956 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 907573 T2505 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 907574 T2505 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 907574 T2566 C927 P63956 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 907574 T2505 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 907583 T2505 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 907584 T2538 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:63956_k_np%2Fsf_collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> ASYNC NEW_CORE C928 name=collection1 org.apache.solr.core.SolrCore@185924f url=http://127.0.0.1:63935/k_np/sf/collection1 node=127.0.0.1:63935_k_np%2Fsf C928_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:63935_k_np%2Fsf, base_url=http://127.0.0.1:63935/k_np/sf, leader=true}
[junit4:junit4] 2> 907597 T2523 C928 P63935 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@f73246 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1ff9db0),segFN=segments_1,generation=1}
[junit4:junit4] 2> 907597 T2523 C928 P63935 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 907601 T2518 C928 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[1 (1437889081836044289)]} 0 6
[junit4:junit4] 2> 907601 T2523 C928 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10001 (1437889081836044288)]} 0 7
[junit4:junit4] 2> ASYNC NEW_CORE C929 name=collection1 org.apache.solr.core.SolrCore@32b31c url=http://127.0.0.1:63947/k_np/sf/collection1 node=127.0.0.1:63947_k_np%2Fsf C929_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:63947_k_np%2Fsf, base_url=http://127.0.0.1:63947/k_np/sf, leader=true}
[junit4:junit4] 2> 907618 T2540 C929 P63947 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4a1f46 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6fa52d),segFN=segments_1,generation=1}
[junit4:junit4] 2> 907618 T2540 C929 P63947 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 907621 T2541 C929 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[1 (1437889081857015808)]} 0 6
[junit4:junit4] 2> 907623 T2540 C929 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10001 (1437889081855967232)]} 0 10
[junit4:junit4] 2> 907681 T2519 C928 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10002 (1437889081925173249)]} 0 1
[junit4:junit4] 2> 907682 T2520 C928 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[2 (1437889081925173248)]} 0 2
[junit4:junit4] 2> 907685 T2542 C929 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10002 (1437889081929367552)]} 0 1
[junit4:junit4] 2> 907686 T2543 C929 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[2 (1437889081930416128)]} 0 1
[junit4:junit4] 2> 907740 T2522 C928 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10003 (1437889081987039232)]} 0 1
[junit4:junit4] 2> 907740 T2523 C928 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[3 (1437889081987039233)]} 0 1
[junit4:junit4] 2> 907745 T2539 C929 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10003 (1437889081991233536)]} 0 2
[junit4:junit4] 2> 907745 T2541 C929 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[3 (1437889081991233537)]} 0 2
[junit4:junit4] 2> ASYNC NEW_CORE C930 name=collection1 org.apache.solr.core.SolrCore@185924f url=http://127.0.0.1:63935/k_np/sf/collection1 node=127.0.0.1:63935_k_np%2Fsf C930_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:63935_k_np%2Fsf, base_url=http://127.0.0.1:63935/k_np/sf, leader=true}
[junit4:junit4] 2> 907784 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10001 (-1437889082034225152)]} 0 1
[junit4:junit4] 2> 907794 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[1 (-1437889082044710912)]} 0 0
[junit4:junit4] 2> ASYNC NEW_CORE C931 name=collection1 org.apache.solr.core.SolrCore@32b31c url=http://127.0.0.1:63947/k_np/sf/collection1 node=127.0.0.1:63947_k_np%2Fsf C931_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:63947_k_np%2Fsf, base_url=http://127.0.0.1:63947/k_np/sf, leader=true}
[junit4:junit4] 2> 907797 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10001 (-1437889082047856640)]} 0 1
[junit4:junit4] 2> 907797 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[1 (-1437889082047856641)]} 0 0
[junit4:junit4] 2> 907801 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[4 (1437889082051002368)]} 0 1
[junit4:junit4] 2> 907803 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10004 (1437889082049953792)]} 0 4
[junit4:junit4] 2> 907805 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[4 (1437889082056245248)]} 0 0
[junit4:junit4] 2> 907807 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10004 (1437889082058342400)]} 0 1
[junit4:junit4] 2> 907845 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[2 (-1437889082098188288)]} 0 0
[junit4:junit4] 2> 907847 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10002 (-1437889082100285440)]} 0 0
[junit4:junit4] 2> 907848 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[2 (-1437889082101334016)]} 0 0
[junit4:junit4] 2> 907849 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10002 (-1437889082102382592)]} 0 0
[junit4:junit4] 2> 907851 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[5 (1437889082104479744)]} 0 0
[junit4:junit4] 2> 907852 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10005 (1437889082104479745)]} 0 1
[junit4:junit4] 2> 907853 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[5 (1437889082106576896)]} 0 0
[junit4:junit4] 2> 907854 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10005 (1437889082107625472)]} 0 0
[junit4:junit4] 2> 907867 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[6 (1437889082121256960)]} 0 0
[junit4:junit4] 2> 907869 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10006 (1437889082123354112)]} 0 0
[junit4:junit4] 2> 907870 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[6 (1437889082124402688)]} 0 0
[junit4:junit4] 2> 907872 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10006 (1437889082125451264)]} 0 1
[junit4:junit4] 2> 907890 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[3 (-1437889082145374208)]} 0 0
[junit4:junit4] 2> 907890 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10003 (-1437889082145374209)]} 0 0
[junit4:junit4] 2> 907894 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[3 (-1437889082148519936)]} 0 1
[junit4:junit4] 2> 907895 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10003 (-1437889082150617088)]} 0 1
[junit4:junit4] 2> 907898 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10007 (1437889082153762816)]} 0 1
[junit4:junit4] 2> 907898 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[7 (1437889082153762817)]} 0 1
[junit4:junit4] 2> 907902 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10007 (1437889082156908544)]} 0 1
[junit4:junit4] 2> 907902 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[7 (1437889082157957120)]} 0 0
[junit4:junit4] 2> 907964 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10008 (1437889082221920256)]} 0 2
[junit4:junit4] 2> 907965 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[8 (1437889082222968832)]} 0 1
[junit4:junit4] 2> 907968 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10008 (1437889082227163136)]} 0 1
[junit4:junit4] 2> 907968 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[8 (1437889082227163137)]} 0 0
[junit4:junit4] 2> 908001 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10009 (1437889082260717568)]} 0 1
[junit4:junit4] 2> 908004 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[9 (1437889082263863296)]} 0 2
[junit4:junit4] 2> 908005 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10009 (1437889082263863296)]} 0 2
[junit4:junit4] 2> 908007 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[9 (1437889082267009024)]} 0 1
[junit4:junit4] 2> 908057 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10010 (1437889082318389248)]} 0 2
[junit4:junit4] 2> 908059 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10 (1437889082321534976)]} 0 1
[junit4:junit4] 2> 908061 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10010 (1437889082323632128)]} 0 1
[junit4:junit4] 2> 908063 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10 (1437889082325729280)]} 0 1
[junit4:junit4] 2> 908076 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10011 (1437889082340409344)]} 0 0
[junit4:junit4] 2> 908079 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[11 (1437889082342506496)]} 0 1
[junit4:junit4] 2> 908081 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10011 (1437889082344603648)]} 0 2
[junit4:junit4] 2> 908083 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[11 (1437889082346700800)]} 0 1
[junit4:junit4] 2> 908109 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10012 (1437889082373963776)]} 0 1
[junit4:junit4] 2> 908110 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[12 (1437889082376060928)]} 0 0
[junit4:junit4] 2> 908114 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10012 (1437889082378158080)]} 0 2
[junit4:junit4] 2> 908115 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[12 (1437889082380255232)]} 0 1
[junit4:junit4] 2> 908168 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10013 (1437889082435829760)]} 0 1
[junit4:junit4] 2> 908170 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[13 (1437889082437926912)]} 0 1
[junit4:junit4] 2> 908172 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10013 (1437889082440024064)]} 0 1
[junit4:junit4] 2> 908174 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[13 (1437889082443169792)]} 0 1
[junit4:junit4] 2> 908237 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10010 (-1437889082509230080)]} 0 0
[junit4:junit4] 2> 908238 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10 (-1437889082509230081)]} 0 0
[junit4:junit4] 2> 908240 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10010 (-1437889082512375808)]} 0 0
[junit4:junit4] 2> 908242 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10 (-1437889082514472960)]} 0 1
[junit4:junit4] 2> 908243 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10014 (1437889082515521536)]} 0 0
[junit4:junit4] 2> 908246 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[14 (1437889082517618688)]} 0 1
[junit4:junit4] 2> 908247 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10014 (1437889082519715840)]} 0 1
[junit4:junit4] 2> 908252 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[14 (1437889082523910144)]} 0 2
[junit4:junit4] 2> 908291 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10015 (1437889082565853184)]} 0 0
[junit4:junit4] 2> 908294 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[15 (1437889082567950336)]} 0 1
[junit4:junit4] 2> 908294 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10015 (1437889082568998912)]} 0 0
[junit4:junit4] 2> 908298 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[15 (1437889082573193216)]} 0 1
[junit4:junit4] 2> 908364 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10014 (-1437889082642399232)]} 0 0
[junit4:junit4] 2> 908367 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[14 (-1437889082645544960)]} 0 0
[junit4:junit4] 2> 908367 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10014 (-1437889082645544960)]} 0 0
[junit4:junit4] 2> 908370 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[14 (-1437889082648690688)]} 0 0
[junit4:junit4] 2> 908371 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10016 (1437889082648690688)]} 0 1
[junit4:junit4] 2> 908373 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[16 (1437889082651836416)]} 0 0
[junit4:junit4] 2> 908374 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10016 (1437889082651836416)]} 0 1
[junit4:junit4] 2> 908378 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[16 (1437889082656030720)]} 0 1
[junit4:junit4] 2> 908424 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10017 (1437889082704265216)]} 0 1
[junit4:junit4] 2> 908429 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[17 (1437889082709508096)]} 0 2
[junit4:junit4] 2> 908429 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10017 (1437889082710556672)]} 0 0
[junit4:junit4] 2> 908432 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[17 (1437889082712653824)]} 0 1
[junit4:junit4] 2> 908442 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10018 (1437889082723139584)]} 0 1
[junit4:junit4] 2> 908445 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[18 (1437889082727333888)]} 0 1
[junit4:junit4] 2> 908446 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10018 (1437889082727333888)]} 0 1
[junit4:junit4] 2> 908450 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[18 (1437889082731528192)]} 0 1
[junit4:junit4] 2> 908511 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10019 (1437889082795491328)]} 0 1
[junit4:junit4] 2> 908513 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[19 (1437889082798637056)]} 0 1
[junit4:junit4] 2> 908516 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10019 (1437889082800734208)]} 0 2
[junit4:junit4] 2> 908519 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[19 (1437889082803879936)]} 0 1
[junit4:junit4] 2> 908550 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10015 (-1437889082837434368)]} 0 0
[junit4:junit4] 2> 908553 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[15 (-1437889082839531520)]} 0 1
[junit4:junit4] 2> 908554 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10015 (-1437889082841628672)]} 0 1
[junit4:junit4] 2> 908556 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[15 (-1437889082843725824)]} 0 0
[junit4:junit4] 2> 908558 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10020 (1437889082844774400)]} 0 0
[junit4:junit4] 2> 908560 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[20 (1437889082846871552)]} 0 1
[junit4:junit4] 2> 908562 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10020 (1437889082848968704)]} 0 1
[junit4:junit4] 2> 908565 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[20 (1437889082852114432)]} 0 1
[junit4:junit4] 2> 908603 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10017 (-1437889082893008896)]} 0 1
[junit4:junit4] 2> 908606 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[17 (-1437889082895106048)]} 0 1
[junit4:junit4] 2> 908607 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10017 (-1437889082897203200)]} 0 0
[junit4:junit4] 2> 908611 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[17 (-1437889082900348928)]} 0 1
[junit4:junit4] 2> 908612 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10021 (1437889082901397504)]} 0 1
[junit4:junit4] 2> 908614 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[21 (1437889082903494656)]} 0 1
[junit4:junit4] 2> 908616 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10021 (1437889082906640384)]} 0 1
[junit4:junit4] 2> 908623 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[21 (1437889082913980416)]} 0 5
[junit4:junit4] 2> 908653 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10022 (1437889082945437696)]} 0 1
[junit4:junit4] 2> 908658 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10022 (1437889082950680576)]} 0 1
[junit4:junit4] 2> 908660 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[22 (1437889082950680576)]} 0 2
[junit4:junit4] 2> 908664 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[22 (1437889082955923456)]} 0 1
[junit4:junit4] 2> 908686 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10018 (-1437889082980040704)]} 0 1
[junit4:junit4] 2> 908689 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10018 (-1437889082983186432)]} 0 0
[junit4:junit4] 2> 908692 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[18 (-1437889082985283584)]} 0 1
[junit4:junit4] 2> 908693 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10023 (1437889082986332160)]} 0 1
[junit4:junit4] 2> 908695 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[18 (-1437889082988429312)]} 0 1
[junit4:junit4] 2> 908696 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10023 (1437889082990526464)]} 0 0
[junit4:junit4] 2> 908699 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[23 (1437889082993672192)]} 0 0
[junit4:junit4] 2> 908703 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[23 (1437889082996817920)]} 0 1
[junit4:junit4] 2> 908737 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10019 (-1437889083033518080)]} 0 2
[junit4:junit4] 2> 908741 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10019 (-1437889083037712384)]} 0 1
[junit4:junit4] 2> 908741 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[19 (-1437889083037712384)]} 0 1
[junit4:junit4] 2> 908746 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[19 (-1437889083042955264)]} 0 0
[junit4:junit4] 2> 908747 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10024 (1437889083041906688)]} 0 2
[junit4:junit4] 2> 908750 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[24 (1437889083047149568)]} 0 1
[junit4:junit4] 2> 908755 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10024 (1437889083048198144)]} 0 5
[junit4:junit4] 2> 908755 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[24 (1437889083050295296)]} 0 2
[junit4:junit4] 2> 908757 T2528 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 908760 T2528 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:63956_k_np%2Fsf_collection1",
[junit4:junit4] 2> "numShards":"1",
[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:63956_k_np%2Fsf",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63956/k_np/sf"}
[junit4:junit4] 2> 908784 T2563 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> 908785 T2527 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> 908785 T2547 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> 908786 T2534 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> 908819 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10023 (-1437889083119501312)]} 0 0
[junit4:junit4] 2> 908819 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[23 (-1437889083119501313)]} 0 0
[junit4:junit4] 2> ASYNC NEW_CORE C932 name=collection1 org.apache.solr.core.SolrCore@16aa6e8 url=http://127.0.0.1:63956/k_np/sf/collection1 node=127.0.0.1:63956_k_np%2Fsf C932_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:63956_k_np%2Fsf, base_url=http://127.0.0.1:63956/k_np/sf}
[junit4:junit4] 2> 908846 T2555 C932 P63956 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@a89caf lockFactory=org.apache.lucene.store.NativeFSLockFactory@14ed00a),segFN=segments_1,generation=1}
[junit4:junit4] 2> 908846 T2555 C932 P63956 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 908849 T2555 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[23 (-1437889083122647040)]} 0 7
[junit4:junit4] 2> 908849 T2556 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10023 (-1437889083123695616)]} 0 7
[junit4:junit4] 2> 908851 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[23 (-1437889083122647040)]} 0 29
[junit4:junit4] 2> 908852 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10023 (-1437889083123695616)]} 0 30
[junit4:junit4] 2> 908854 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[25 (1437889083155152896)]} 0 1
[junit4:junit4] 2> 908854 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10025 (1437889083156201472)]} 0 0
[junit4:junit4] 2> 908859 T2557 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10025 (1437889083159347200)]} 0 1
[junit4:junit4] 2> 908860 T2558 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[25 (1437889083158298624)]} 0 2
[junit4:junit4] 2> 908860 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10025 (1437889083159347200)]} 0 3
[junit4:junit4] 2> 908861 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[25 (1437889083158298624)]} 0 5
[junit4:junit4] 2> 908914 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[26 (1437889083218067456)]} 0 1
[junit4:junit4] 2> 908914 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10026 (1437889083218067457)]} 0 1
[junit4:junit4] 2> 908924 T2559 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[26 (1437889083223310336)]} 0 3
[junit4:junit4] 2> 908925 T2553 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10026 (1437889083223310337)]} 0 2
[junit4:junit4] 2> 908926 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[26 (1437889083223310336)]} 0 8
[junit4:junit4] 2> 908927 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10026 (1437889083223310337)]} 0 9
[junit4:junit4] 2> 908985 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[25 (-1437889083293564928)]} 0 0
[junit4:junit4] 2> 908985 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10025 (-1437889083293564929)]} 0 0
[junit4:junit4] 2> 908989 T2555 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[25 (-1437889083296710656)]} 0 0
[junit4:junit4] 2> 908990 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[25 (-1437889083296710656)]} 0 2
[junit4:junit4] 2> 908990 T2555 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10025 (-1437889083297759232)]} 0 0
[junit4:junit4] 2> 908992 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10025 (-1437889083297759232)]} 0 3
[junit4:junit4] 2> 908993 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[27 (1437889083301953536)]} 0 0
[junit4:junit4] 2> 908994 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10027 (1437889083303002112)]} 0 0
[junit4:junit4] 2> 908998 T2557 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[27 (1437889083304050688)]} 0 0
[junit4:junit4] 2> 908999 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[27 (1437889083304050688)]} 0 4
[junit4:junit4] 2> 908999 T2558 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10027 (1437889083306147840)]} 0 0
[junit4:junit4] 2> 909000 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10027 (1437889083306147840)]} 0 3
[junit4:junit4] 2> 909028 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[28 (1437889083337605120)]} 0 1
[junit4:junit4] 2> 909028 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10028 (1437889083338653696)]} 0 0
[junit4:junit4] 2> 909032 T2559 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[28 (1437889083340750848)]} 0 0
[junit4:junit4] 2> 909033 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[28 (1437889083340750848)]} 0 3
[junit4:junit4] 2> 909034 T2553 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10028 (1437889083340750849)]} 0 1
[junit4:junit4] 2> 909034 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10028 (1437889083340750849)]} 0 4
[junit4:junit4] 2> 909114 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[29 (1437889083427782656)]} 0 1
[junit4:junit4] 2> 909115 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10029 (1437889083428831232)]} 0 1
[junit4:junit4] 2> 909120 T2556 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[29 (1437889083431976960)]} 0 1
[junit4:junit4] 2> 909121 T2555 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10029 (1437889083431976961)]} 0 1
[junit4:junit4] 2> 909121 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[29 (1437889083431976960)]} 0 4
[junit4:junit4] 2> 909122 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10029 (1437889083431976961)]} 0 5
[junit4:junit4] 2> 909195 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[28 (-1437889083513765888)]} 0 0
[junit4:junit4] 2> 909197 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10028 (-1437889083515863040)]} 0 0
[junit4:junit4] 2> 909199 T2557 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[28 (-1437889083516911616)]} 0 0
[junit4:junit4] 2> 909200 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[28 (-1437889083516911616)]} 0 2
[junit4:junit4] 2> 909201 T2559 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10028 (-1437889083517960192)]} 0 0
[junit4:junit4] 2> 909202 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10028 (-1437889083517960192)]} 0 3
[junit4:junit4] 2> 909203 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[30 (1437889083522154496)]} 0 0
[junit4:junit4] 2> 909203 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10030 (1437889083522154497)]} 0 0
[junit4:junit4] 2> 909208 T2553 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10030 (1437889083525300224)]} 0 0
[junit4:junit4] 2> 909208 T2556 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[30 (1437889083524251648)]} 0 0
[junit4:junit4] 2> 909208 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10030 (1437889083525300224)]} 0 2
[junit4:junit4] 2> 909209 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[30 (1437889083524251648)]} 0 4
[junit4:junit4] 2> 909218 T2538 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:63956_k_np%2Fsf_collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 909218 T2538 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:63956_k_np%252Fsf_collection1&state=recovering&nodeName=127.0.0.1:63956_k_np%252Fsf&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1634
[junit4:junit4] 2> 909220 T2505 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 63956
[junit4:junit4] 2> 909220 T2505 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=19697619
[junit4:junit4] 2> 909235 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[30 (-1437889083555708928)]} 0 0
[junit4:junit4] 2> 909235 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10030 (-1437889083555708929)]} 0 0
[junit4:junit4] 2> 909239 T2555 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10030 (-1437889083558854656)]} 0 0
[junit4:junit4] 2> 909239 T2558 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[30 (-1437889083558854657)]} 0 0
[junit4:junit4] 2> 909240 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10030 (-1437889083558854656)]} 0 2
[junit4:junit4] 2> 909241 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[30 (-1437889083558854657)]} 0 3
[junit4:junit4] 2> 909243 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10031 (1437889083564097536)]} 0 0
[junit4:junit4] 2> 909244 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[31 (1437889083565146112)]} 0 0
[junit4:junit4] 2> 909249 T2557 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[31 (1437889083567243264)]} 0 1
[junit4:junit4] 2> 909249 T2559 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10031 (1437889083566194688)]} 0 1
[junit4:junit4] 2> 909249 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[31 (1437889083567243264)]} 0 3
[junit4:junit4] 2> 909249 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10031 (1437889083566194688)]} 0 4
[junit4:junit4] 2> 909282 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10032 (1437889083603943424)]} 0 1
[junit4:junit4] 2> 909283 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[32 (1437889083604992000)]} 0 1
[junit4:junit4] 2> 909288 T2553 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10032 (1437889083607089152)]} 0 1
[junit4:junit4] 2> 909290 T2538 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10032 (1437889083607089152)]} 0 6
[junit4:junit4] 2> 909290 T2556 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[32 (1437889083608137728)]} 0 0
[junit4:junit4] 2> 909291 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[32 (1437889083608137728)]} 0 6
[junit4:junit4] 2> 909373 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10033 (1437889083699363840)]} 0 1
[junit4:junit4] 2> 909373 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[33 (1437889083699363841)]} 0 1
[junit4:junit4] 2> 909380 T2555 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10033 (1437889083703558144)]} 0 1
[junit4:junit4] 2> 909381 T2558 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[33 (1437889083703558145)]} 0 2
[junit4:junit4] 2> 909381 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10033 (1437889083703558144)]} 0 5
[junit4:junit4] 2> 909382 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[33 (1437889083703558145)]} 0 6
[junit4:junit4] 2> 909418 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10033 (-1437889083746549760)]} 0 1
[junit4:junit4] 2> 909418 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[33 (-1437889083747598336)]} 0 0
[junit4:junit4] 2> 909422 T2557 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10033 (-1437889083750744064)]} 0 0
[junit4:junit4] 2> 909423 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10033 (-1437889083750744064)]} 0 2
[junit4:junit4] 2> 909425 T2559 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[33 (-1437889083751792640)]} 0 0
[junit4:junit4] 2> 909427 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[33 (-1437889083751792640)]} 0 5
[junit4:junit4] 2> 909428 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10034 (1437889083757035520)]} 0 1
[junit4:junit4] 2> 909432 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[34 (1437889083761229824)]} 0 1
[junit4:junit4] 2> 909435 T2553 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10034 (1437889083761229824)]} 0 1
[junit4:junit4] 2> 909437 T2538 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10034 (1437889083761229824)]} 0 6
[junit4:junit4] 2> 909438 T2553 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[34 (1437889083764375552)]} 0 1
[junit4:junit4] 2> 909439 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[34 (1437889083764375552)]} 0 5
[junit4:junit4] 2> 909503 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10035 (1437889083836727296)]} 0 0
[junit4:junit4] 2> 909505 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[35 (1437889083837775872)]} 0 1
[junit4:junit4] 2> 909510 T2555 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10035 (1437889083840921600)]} 0 1
[junit4:junit4] 2> 909512 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10035 (1437889083840921600)]} 0 5
[junit4:junit4] 2> 909515 T2555 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[35 (1437889083843018752)]} 0 1
[junit4:junit4] 2> 909516 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[35 (1437889083843018752)]} 0 8
[junit4:junit4] 2> 909587 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10034 (-1437889083924807680)]} 0 0
[junit4:junit4] 2> 909590 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[34 (-1437889083926904832)]} 0 1
[junit4:junit4] 2> 909595 T2557 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10034 (-1437889083929001984)]} 0 0
[junit4:junit4] 2> 909595 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10034 (-1437889083929001984)]} 0 4
[junit4:junit4] 2> 909596 T2557 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[34 (-1437889083932147712)]} 0 0
[junit4:junit4] 2> 909598 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[34 (-1437889083932147712)]} 0 5
[junit4:junit4] 2> 909599 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10036 (1437889083937390592)]} 0 1
[junit4:junit4] 2> 909601 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[36 (1437889083939487744)]} 0 1
[junit4:junit4] 2> 909607 T2556 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10036 (1437889083941584896)]} 0 1
[junit4:junit4] 2> 909609 T2538 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10036 (1437889083941584896)]} 0 6
[junit4:junit4] 2> 909610 T2558 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[36 (1437889083944730624)]} 0 0
[junit4:junit4] 2> 909612 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[36 (1437889083944730624)]} 0 7
[junit4:junit4] 2> 909681 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10037 (1437889084023373824)]} 0 2
[junit4:junit4] 2> 909684 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[37 (1437889084025470976)]} 0 1
[junit4:junit4] 2> 909690 T2555 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10037 (1437889084028616704)]} 0 1
[junit4:junit4] 2> 909692 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10037 (1437889084028616704)]} 0 6
[junit4:junit4] 2> 909693 T2555 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[37 (1437889084029665280)]} 0 1
[junit4:junit4] 2> 909695 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[37 (1437889084029665280)]} 0 8
[junit4:junit4] 2> 909768 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10038 (1437889084114599936)]} 0 1
[junit4:junit4] 2> 909773 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[38 (1437889084118794240)]} 0 2
[junit4:junit4] 2> 909776 T2557 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10038 (1437889084118794240)]} 0 2
[junit4:junit4] 2> 909777 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10038 (1437889084118794240)]} 0 5
[junit4:junit4] 2> 909780 T2553 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[38 (1437889084121939968)]} 0 1
[junit4:junit4] 2> 909782 T2538 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[38 (1437889084121939968)]} 0 7
[junit4:junit4] 2> 909810 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10039 (1437889084157591552)]} 0 1
[junit4:junit4] 2> 909814 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[39 (1437889084162834432)]} 0 0
[junit4:junit4] 2> 909816 T2556 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10039 (1437889084161785856)]} 0 0
[junit4:junit4] 2> 909819 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10039 (1437889084161785856)]} 0 6
[junit4:junit4] 2> 909823 T2558 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[39 (1437889084167028736)]} 0 2
[junit4:junit4] 2> 909824 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[39 (1437889084167028736)]} 0 6
[junit4:junit4] 2> 909885 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10040 (1437889084237283328)]} 0 1
[junit4:junit4] 2> 909893 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[40 (1437889084244623360)]} 0 1
[junit4:junit4] 2> 909897 T2559 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10040 (1437889084244623360)]} 0 1
[junit4:junit4] 2> 909900 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10040 (1437889084244623360)]} 0 8
[junit4:junit4] 2> 909901 T2555 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[40 (1437889084251963392)]} 0 0
[junit4:junit4] 2> 909903 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[40 (1437889084251963392)]} 0 5
[junit4:junit4] 2> 909976 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10041 (1437889084332703744)]} 0 0
[junit4:junit4] 2> 909979 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[41 (1437889084334800896)]} 0 1
[junit4:junit4] 2> 909984 T2557 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10041 (1437889084337946624)]} 0 1
[junit4:junit4] 2> 909986 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10041 (1437889084337946624)]} 0 6
[junit4:junit4] 2> 909987 T2553 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[41 (1437889084340043776)]} 0 1
[junit4:junit4] 2> 909989 T2538 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[41 (1437889084340043776)]} 0 7
[junit4:junit4] 2> 909991 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10035 (-1437889084348432384)]} 0 0
[junit4:junit4] 2> 909995 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[35 (-1437889084351578112)]} 0 1
[junit4:junit4] 2> 909998 T2556 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10035 (-1437889084351578112)]} 0 1
[junit4:junit4] 2> 909999 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10035 (-1437889084351578112)]} 0 5
[junit4:junit4] 2> 910002 T2558 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[35 (-1437889084356820992)]} 0 1
[junit4:junit4] 2> 910003 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[35 (-1437889084356820992)]} 0 4
[junit4:junit4] 2> 910003 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10042 (1437889084359966720)]} 0 1
[junit4:junit4] 2> 910007 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[42 (1437889084364161024)]} 0 1
[junit4:junit4] 2> 910012 T2559 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10042 (1437889084366258176)]} 0 1
[junit4:junit4] 2> 910014 T2557 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[42 (1437889084367306752)]} 0 2
[junit4:junit4] 2> 910014 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10042 (1437889084366258176)]} 0 7
[junit4:junit4] 2> 910017 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[42 (1437889084367306752)]} 0 8
[junit4:junit4] 2> 910043 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10043 (1437889084401909760)]} 0 2
[junit4:junit4] 2> 910046 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[43 (1437889084404006912)]} 0 2
[junit4:junit4] 2> 910050 T2553 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10043 (1437889084407152640)]} 0 1
[junit4:junit4] 2> 910052 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10043 (1437889084407152640)]} 0 6
[junit4:junit4] 2> 910053 T2556 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[43 (1437889084409249792)]} 0 0
[junit4:junit4] 2> 910054 T2538 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[43 (1437889084409249792)]} 0 5
[junit4:junit4] 2> 910086 T2528 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 910088 T2528 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:63956_k_np%2Fsf_collection1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:63956_k_np%2Fsf",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63956/k_np/sf"}
[junit4:junit4] 2> 910110 T2563 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> 910111 T2527 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> 910112 T2534 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> 910112 T2547 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> 910140 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10036 (-1437889084504670208)]} 0 0
[junit4:junit4] 2> 910140 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[36 (-1437889084504670209)]} 0 0
[junit4:junit4] 2> 910144 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10036 (-1437889084507815936)]} 0 1
[junit4:junit4] 2> 910145 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[36 (-1437889084509913088)]} 0 0
[junit4:junit4] 2> 910148 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10044 (1437889084510961664)]} 0 2
[junit4:junit4] 2> 910149 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[44 (1437889084513058816)]} 0 1
[junit4:junit4] 2> 910152 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10044 (1437889084516204544)]} 0 1
[junit4:junit4] 2> 910154 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[44 (1437889084518301696)]} 0 2
[junit4:junit4] 2> 910235 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10045 (1437889084602187776)]} 0 2
[junit4:junit4] 2> 910236 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[45 (1437889084605333504)]} 0 1
[junit4:junit4] 2> 910237 T2538 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10045 (1437889084606382080)]} 0 0
[junit4:junit4] 2> 910239 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[45 (1437889084608479232)]} 0 0
[junit4:junit4] 2> 910318 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10038 (-1437889084691316736)]} 0 0
[junit4:junit4] 2> 910318 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[38 (-1437889084691316737)]} 0 0
[junit4:junit4] 2> 910323 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10038 (-1437889084696559616)]} 0 1
[junit4:junit4] 2> 910325 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[38 (-1437889084698656768)]} 0 0
[junit4:junit4] 2> 910328 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10046 (1437889084700753920)]} 0 2
[junit4:junit4] 2> 910330 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[46 (1437889084702851072)]} 0 1
[junit4:junit4] 2> 910332 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10046 (1437889084704948224)]} 0 1
[junit4:junit4] 2> 910335 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[46 (1437889084707045376)]} 0 2
[junit4:junit4] 2> 910395 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10042 (-1437889084772057088)]} 0 1
[junit4:junit4] 2> 910399 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[42 (-1437889084776251392)]} 0 1
[junit4:junit4] 2> 910399 T2538 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10042 (-1437889084776251392)]} 0 0
[junit4:junit4] 2> 910402 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[42 (-1437889084778348544)]} 0 1
[junit4:junit4] 2> 910403 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10047 (1437889084779397120)]} 0 1
[junit4:junit4] 2> 910405 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[47 (1437889084781494272)]} 0 1
[junit4:junit4] 2> 910407 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10047 (1437889084783591424)]} 0 1
[junit4:junit4] 2> 910409 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[47 (1437889084785688576)]} 0 1
[junit4:junit4] 2> 910467 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10048 (1437889084846505984)]} 0 1
[junit4:junit4] 2> 910470 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[48 (1437889084849651712)]} 0 1
[junit4:junit4] 2> 910474 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10048 (1437889084852797440)]} 0 2
[junit4:junit4] 2> 910476 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[48 (1437889084855943168)]} 0 1
[junit4:junit4] 2> 910524 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10049 (1437889084906274816)]} 0 1
[junit4:junit4] 2> 910526 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[49 (1437889084908371968)]} 0 2
[junit4:junit4] 2> 910527 T2538 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10049 (1437889084909420544)]} 0 1
[junit4:junit4] 2> 910530 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[49 (1437889084912566272)]} 0 2
[junit4:junit4] 2> 910573 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10050 (1437889084957655040)]} 0 1
[junit4:junit4] 2> 910574 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[50 (1437889084958703616)]} 0 1
[junit4:junit4] 2> 910577 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10050 (1437889084962897920)]} 0 1
[junit4:junit4] 2> 910578 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[50 (1437889084962897921)]} 0 1
[junit4:junit4] 2> 910608 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10051 (1437889084995403776)]} 0 0
[junit4:junit4] 2> 910609 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[51 (1437889084995403777)]} 0 1
[junit4:junit4] 2> 910613 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10051 (1437889085000646656)]} 0 1
[junit4:junit4] 2> 910613 T2538 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[51 (1437889085000646657)]} 0 0
[junit4:junit4] 2> 910691 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10052 (1437889085081387008)]} 0 2
[junit4:junit4] 2> 910691 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[52 (1437889085081387009)]} 0 1
[junit4:junit4] 2> 910694 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10052 (1437889085085581312)]} 0 0
[junit4:junit4] 2> 910696 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[52 (1437889085085581313)]} 0 2
[junit4:junit4] 2> 910729 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10043 (-1437889085122281472)]} 0 0
[junit4:junit4] 2> 910730 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[43 (-1437889085123330048)]} 0 0
[junit4:junit4] 2> 910732 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10043 (-1437889085125427200)]} 0 0
[junit4:junit4] 2> 910735 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[43 (-1437889085128572928)]} 0 1
[junit4:junit4] 2> 910736 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10053 (1437889085128572928)]} 0 1
[junit4:junit4] 2> 910739 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[53 (1437889085132767232)]} 0 1
[junit4:junit4] 2> 910740 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10053 (1437889085133815808)]} 0 0
[junit4:junit4] 2> 910743 T2538 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[53 (1437889085136961536)]} 0 1
[junit4:junit4] 2> 910758 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10044 (-1437889085151641600)]} 0 1
[junit4:junit4] 2> 910761 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[44 (-1437889085155835904)]} 0 0
[junit4:junit4] 2> 910761 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10044 (-1437889085155835904)]} 0 0
[junit4:junit4] 2> 910766 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[44 (-1437889085161078784)]} 0 1
[junit4:junit4] 2> 910767 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10054 (1437889085161078784)]} 0 1
[junit4:junit4] 2> 910771 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[54 (1437889085164224512)]} 0 2
[junit4:junit4] 2> 910771 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10054 (1437889085165273088)]} 0 1
[junit4:junit4] 2> 910773 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[54 (1437889085167370240)]} 0 1
[junit4:junit4] 2> 910822 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10045 (-1437889085219799040)]} 0 0
[junit4:junit4] 2> 910824 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[45 (-1437889085221896192)]} 0 0
[junit4:junit4] 2> 910824 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10045 (-1437889085221896192)]} 0 0
[junit4:junit4] 2> 910827 T2538 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[45 (-1437889085225041920)]} 0 0
[junit4:junit4] 2> 910827 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10055 (1437889085225041920)]} 0 0
[junit4:junit4] 2> 910828 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[55 (1437889085226090496)]} 0 0
[junit4:junit4] 2> 910830 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10055 (1437889085227139072)]} 0 1
[junit4:junit4] 2> 910832 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[55 (1437889085230284800)]} 0 0
[junit4:junit4] 2> 910881 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10056 (1437889085279567872)]} 0 2
[junit4:junit4] 2> 910883 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[56 (1437889085283762176)]} 0 0
[junit4:junit4] 2> 910884 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10056 (1437889085284810752)]} 0 0
[junit4:junit4] 2> 910890 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[56 (1437889085290053632)]} 0 2
[junit4:junit4] 2> 910916 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10057 (1437889085317316608)]} 0 1
[junit4:junit4] 2> 910923 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[57 (1437889085323608064)]} 0 2
[junit4:junit4] 2> 910923 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10057 (1437889085324656640)]} 0 2
[junit4:junit4] 2> 910928 T2538 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[57 (1437889085329899520)]} 0 1
[junit4:junit4] 2> C932_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=down, core=collection1, collection=collection1, node_name=127.0.0.1:63956_k_np%2Fsf, base_url=http://127.0.0.1:63956/k_np/sf}
[junit4:junit4] 2> 910929 T2566 C932 P63956 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:63947/k_np/sf/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 910930 T2566 C932 P63956 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:63956/k_np/sf START replicas=[http://127.0.0.1:63947/k_np/sf/collection1/] nUpdates=100
[junit4:junit4] 2> 910933 T2566 C932 P63956 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 910934 T2566 C932 P63956 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 910934 T2566 C932 P63956 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 910935 T2566 C932 P63956 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 910935 T2566 C932 P63956 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=tlog{file=.\org.apache.solr.cloud.RecoveryZkTest-1371277875140\jetty2\tlog\tlog.0000000000000000000 refcount=1}}
[junit4:junit4] 2> 910935 T2566 C932 P63956 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:63947/k_np/sf/collection1/. core=collection1
[junit4:junit4] 2> 910936 T2566 C932 P63956 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 910936 T2542 C931 P63947 oasc.SolrCore.execute [collection1] webapp=/k_np/sf path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 910944 T2543 C931 P63947 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 910950 T2543 C931 P63947 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4a1f46 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6fa52d),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4a1f46 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6fa52d),segFN=segments_2,generation=2}
[junit4:junit4] 2> 910951 T2543 C931 P63947 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 910953 T2543 C931 P63947 oass.SolrIndexSearcher.<init> Opening Searcher@b62bbd realtime
[junit4:junit4] 2> 910953 T2543 C931 P63947 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 910953 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 9
[junit4:junit4] 2> 910954 T2566 C932 P63956 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 910954 T2566 C932 P63956 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 910956 T2539 C931 P63947 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 910956 T2539 C931 P63947 oasc.SolrCore.execute [collection1] webapp=/k_np/sf path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> 910957 T2566 C932 P63956 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 910957 T2566 C932 P63956 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 910957 T2566 C932 P63956 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 910959 T2540 C931 P63947 oasc.SolrCore.execute [collection1] webapp=/k_np/sf path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=0
[junit4:junit4] 2> 910959 T2566 C932 P63956 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 5
[junit4:junit4] 2> 910960 T2566 C932 P63956 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.RecoveryZkTest-1371277875140/jetty2\index.20130615183130552
[junit4:junit4] 2> 910960 T2566 C932 P63956 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@db4ec3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@137537c) fullCopy=false
[junit4:junit4] 2> 910962 T2538 C931 P63947 oasc.SolrCore.execute [collection1] webapp=/k_np/sf path=/replication params={file=_0.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 910962 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10046 (-1437889085366599680)]} 0 0
[junit4:junit4] 2> 910966 T2541 C931 P63947 oasc.SolrCore.execute [collection1] webapp=/k_np/sf path=/replication params={file=_0.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 910967 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[46 (-1437889085371842560)]} 0 0
[junit4:junit4] 2> 910967 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10046 (-1437889085368696832)]} 0 3
[junit4:junit4] 2> 910969 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[46 (-1437889085373939712)]} 0 0
[junit4:junit4] 2> 910969 T2543 C931 P63947 oasc.SolrCore.execute [collection1] webapp=/k_np/sf path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 910970 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10058 (1437889085374988288)]} 0 1
[junit4:junit4] 2> 910973 T2540 C931 P63947 oasc.SolrCore.execute [collection1] webapp=/k_np/sf path=/replication params={file=_0_1.del&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 910973 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[58 (1437889085378134016)]} 0 0
[junit4:junit4] 2> 910974 T2541 C931 P63947 oasc.SolrCore.execute [collection1] webapp=/k_np/sf path=/replication params={file=_0.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 910975 T2566 C932 P63956 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 910975 T2538 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10058 (1437889085379182592)]} 0 1
[junit4:junit4] 2> 910976 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[58 (1437889085380231168)]} 0 1
[junit4:junit4] 2> 910976 T2566 C932 P63956 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 910976 T2566 C932 P63956 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 910977 T2566 C932 P63956 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4:junit4] 2> 910983 T2566 C932 P63956 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@a89caf lockFactory=org.apache.lucene.store.NativeFSLockFactory@14ed00a),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@a89caf lockFactory=org.apache.lucene.store.NativeFSLockFactory@14ed00a),segFN=segments_2,generation=2}
[junit4:junit4] 2> 910984 T2566 C932 P63956 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 910990 T2566 C932 P63956 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@a89caf lockFactory=org.apache.lucene.store.NativeFSLockFactory@14ed00a),segFN=segments_2,generation=2}
[junit4:junit4] 2> 910990 T2566 C932 P63956 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 910990 T2566 C932 P63956 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 910990 T2566 C932 P63956 oass.SolrIndexSearcher.<init> Opening Searcher@4e0d4a main
[junit4:junit4] 2> 910990 T2565 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4e0d4a main{StandardDirectoryReader(segments_2:3:nrt _0(4.4):c38/12)}
[junit4:junit4] 2> 910991 T2566 C932 P63956 oasc.CachingDirectoryFactory.closeCacheValue looking to close .\org.apache.solr.cloud.RecoveryZkTest-1371277875140/jetty2\index.20130615183130552 [CachedDir<<refCount=0;path=.\org.apache.solr.cloud.RecoveryZkTest-1371277875140/jetty2\index.20130615183130552;done=true>>]
[junit4:junit4] 2> 910991 T2566 C932 P63956 oasc.CachingDirectoryFactory.close Closing directory: .\org.apache.solr.cloud.RecoveryZkTest-1371277875140/jetty2\index.20130615183130552
[junit4:junit4] 2> 910991 T2566 C932 P63956 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: .\org.apache.solr.cloud.RecoveryZkTest-1371277875140/jetty2\index.20130615183130552
[junit4:junit4] 2> 910992 T2566 C932 P63956 oasc.RecoveryStrategy.replay Replaying buffered documents. core=collection1
[junit4:junit4] 2> 910992 T2574 C932 P63956 oasu.UpdateLog$LogReplayer.doReplay WARN Starting log replay tlog{file=.\org.apache.solr.cloud.RecoveryZkTest-1371277875140\jetty2\tlog\tlog.0000000000000000000 refcount=2} active=true starting pos=5422
[junit4:junit4] 2> 910992 T2574 C932 P63956 oasu.DirectUpdateHandler2.commit start commit{flags=2,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 910993 T2574 C932 P63956 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@a89caf lockFactory=org.apache.lucene.store.NativeFSLockFactory@14ed00a),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@a89caf lockFactory=org.apache.lucene.store.NativeFSLockFactory@14ed00a),segFN=segments_3,generation=3}
[junit4:junit4] 2> 910993 T2574 C932 P63956 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 910995 T2574 C932 P63956 oass.SolrIndexSearcher.<init> Opening Searcher@ab5a2b main
[junit4:junit4] 2> 910995 T2574 C932 P63956 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 910995 T2565 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@ab5a2b main{StandardDirectoryReader(segments_2:3:nrt _0(4.4):c38/12)}
[junit4:junit4] 2> 910995 T2574 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] {} 0 3
[junit4:junit4] 2> 910995 T2574 C932 P63956 oasu.UpdateLog$LogReplayer.run WARN Log replay finished. recoveryInfo=RecoveryInfo{adds=0 deletes=0 deleteByQuery=0 errors=0 positionOfStart=5422}
[junit4:junit4] 2> 910995 T2566 C932 P63956 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 910995 T2566 C932 P63956 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 910995 T2566 C932 P63956 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 911000 T2566 C932 P63956 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 911009 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10059 (1437889085414834176)]} 0 1
[junit4:junit4] 2> 911010 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[59 (1437889085416931328)]} 0 1
[junit4:junit4] 2> 911013 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10059 (1437889085420077056)]} 0 0
[junit4:junit4] 2> 911014 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[59 (1437889085421125632)]} 0 0
[junit4:junit4] 2> 911071 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10049 (-1437889085480894464)]} 0 0
[junit4:junit4] 2> 911071 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[49 (-1437889085480894465)]} 0 0
[junit4:junit4] 2> 911074 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[49 (-1437889085484040192)]} 0 0
[junit4:junit4] 2> 911074 T2538 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10049 (-1437889085484040193)]} 0 0
[junit4:junit4] 2> 911078 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[60 (1437889085486137344)]} 0 2
[junit4:junit4] 2> 911078 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10060 (1437889085488234496)]} 0 1
[junit4:junit4] 2> 911081 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[60 (1437889085491380224)]} 0 0
[junit4:junit4] 2> 911084 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10060 (1437889085493477376)]} 0 3
[junit4:junit4] 2> 911114 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[61 (1437889085524934656)]} 0 1
[junit4:junit4] 2> 911116 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10061 (1437889085527031808)]} 0 1
[junit4:junit4] 2> 911117 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[61 (1437889085529128960)]} 0 0
[junit4:junit4] 2> 911119 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10061 (1437889085531226112)]} 0 1
[junit4:junit4] 2> 911137 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[50 (-1437889085549051904)]} 0 1
[junit4:junit4] 2> 911139 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10050 (-1437889085552197632)]} 0 2
[junit4:junit4] 2> 911139 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[50 (-1437889085552197632)]} 0 0
[junit4:junit4] 2> 911142 T2538 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10050 (-1437889085555343360)]} 0 0
[junit4:junit4] 2> 911144 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[62 (1437889085556391936)]} 0 1
[junit4:junit4] 2> 911146 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10062 (1437889085558489088)]} 0 1
[junit4:junit4] 2> 911149 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[62 (1437889085561634816)]} 0 1
[junit4:junit4] 2> 911151 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10062 (1437889085563731968)]} 0 1
[junit4:junit4] 2> 911159 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[53 (-1437889085572120576)]} 0 1
[junit4:junit4] 2> 911160 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10053 (-1437889085574217728)]} 0 0
[junit4:junit4] 2> 911164 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[53 (-1437889085578412032)]} 0 0
[junit4:junit4] 2> 911164 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10053 (-1437889085578412033)]} 0 0
[junit4:junit4] 2> 911168 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[63 (1437889085582606337)]} 0 0
[junit4:junit4] 2> 911171 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10063 (1437889085582606336)]} 0 3
[junit4:junit4] 2> 911175 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[63 (1437889085588897792)]} 0 2
[junit4:junit4] 2> 911178 T2538 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10063 (1437889085588897793)]} 0 4
[junit4:junit4] 2> 911224 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[54 (-1437889085641326592)]} 0 1
[junit4:junit4] 2> 911225 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10054 (-1437889085642375168)]} 0 0
[junit4:junit4] 2> 911228 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[54 (-1437889085645520896)]} 0 1
[junit4:junit4] 2> 911229 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10054 (-1437889085645520897)]} 0 1
[junit4:junit4] 2> 911232 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[64 (1437889085648666624)]} 0 2
[junit4:junit4] 2> 911233 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10064 (1437889085649715200)]} 0 1
[junit4:junit4] 2> 911236 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[64 (1437889085652860928)]} 0 2
[junit4:junit4] 2> 911238 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10064 (1437889085653909504)]} 0 2
[junit4:junit4] 2> 911318 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[65 (1437889085738844160)]} 0 2
[junit4:junit4] 2> 911320 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10065 (1437889085740941312)]} 0 2
[junit4:junit4] 2> 911323 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[65 (1437889085744087040)]} 0 1
[junit4:junit4] 2> 911324 T2538 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10065 (1437889085745135616)]} 0 1
[junit4:junit4] 2> 911354 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[66 (1437889085776592896)]} 0 2
[junit4:junit4] 2> 911355 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10066 (1437889085777641472)]} 0 2
[junit4:junit4] 2> 911358 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[66 (1437889085780787200)]} 0 1
[junit4:junit4] 2> 911359 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10066 (1437889085781835776)]} 0 2
[junit4:junit4] 2> 911415 T2528 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 911417 T2528 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:63956_k_np%2Fsf_collection1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:63956_k_np%2Fsf",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63956/k_np/sf"}
[junit4:junit4] 2> 911437 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[55 (-1437889085864673280)]} 0 0
[junit4:junit4] 2> 911439 T2563 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> 911439 T2534 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> 911441 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[55 (-1437889085868867584)]} 0 0
[junit4:junit4] 2> 911437 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10055 (-1437889085864673281)]} 0 0
[junit4:junit4] 2> 911440 T2547 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> 911447 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[67 (1437889085874110464)]} 0 1
[junit4:junit4] 2> 911439 T2527 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> 911449 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10055 (-1437889085877256192)]} 0 1
[junit4:junit4] 2> 911452 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10067 (1437889085880401920)]} 0 0
[junit4:junit4] 2> C932_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:63956_k_np%2Fsf, base_url=http://127.0.0.1:63956/k_np/sf}
[junit4:junit4] 2> 911457 T2559 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[67 (1437889085879353344)]} 0 4
[junit4:junit4] 2> 911458 T2538 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[67 (1437889085879353344)]} 0 7
[junit4:junit4] 2> 911458 T2557 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10067 (1437889085882499072)]} 0 0
[junit4:junit4] 2> 911460 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10067 (1437889085882499072)]} 0 6
[junit4:junit4] 2> 911535 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[68 (1437889085966385152)]} 0 1
[junit4:junit4] 2> 911539 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10068 (1437889085971628032)]} 0 0
[junit4:junit4] 2> 911542 T2553 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[68 (1437889085971628032)]} 0 1
[junit4:junit4] 2> 911544 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[68 (1437889085971628032)]} 0 6
[junit4:junit4] 2> 911549 T2556 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10068 (1437889085976870912)]} 0 2
[junit4:junit4] 2> 911550 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10068 (1437889085976870912)]} 0 6
[junit4:junit4] 2> 911632 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[62 (-1437889086069145600)]} 0 0
[junit4:junit4] 2> 911636 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10062 (-1437889086073339904)]} 0 0
[junit4:junit4] 2> 911640 T2558 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[62 (-1437889086073339904)]} 0 1
[junit4:junit4] 2> 911641 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[62 (-1437889086073339904)]} 0 5
[junit4:junit4] 2> 911643 T2555 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10062 (-1437889086077534208)]} 0 1
[junit4:junit4] 2> 911644 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[10062 (-1437889086077534208)]} 0 4
[junit4:junit4] 2> 911646 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[69 (1437889086082777088)]} 0 1
[junit4:junit4] 2> 911648 T2521 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10069 (1437889086084874240)]} 0 1
[junit4:junit4] 2> 911653 T2559 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[69 (1437889086088019968)]} 0 1
[junit4:junit4] 2> 911656 T2538 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[69 (1437889086088019968)]} 0 7
[junit4:junit4] 2> 911656 T2557 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10069 (1437889086089068544)]} 0 0
[junit4:junit4] 2> 911657 T2539 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10069 (1437889086089068544)]} 0 6
[junit4:junit4] 2> 911699 T2522 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[70 (1437889086138351616)]} 0 1
[junit4:junit4] 2> 911702 T2523 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10070 (1437889086141497344)]} 0 1
[junit4:junit4] 2> 911707 T2553 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[70 (1437889086143594496)]} 0 0
[junit4:junit4] 2> 911709 T2542 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[70 (1437889086143594496)]} 0 6
[junit4:junit4] 2> 911710 T2556 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10070 (1437889086145691648)]} 0 2
[junit4:junit4] 2> 911711 T2540 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10070 (1437889086145691648)]} 0 6
[junit4:junit4] 2> 911764 T2518 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[71 (1437889086206509056)]} 0 2
[junit4:junit4] 2> 911771 T2558 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[71 (1437889086210703360)]} 0 1
[junit4:junit4] 2> 911774 T2543 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[71 (1437889086210703360)]} 0 7
[junit4:junit4] 2> 911778 T2519 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10071 (1437889086221189120)]} 0 1
[junit4:junit4] 2> 911786 T2555 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10071 (1437889086226432000)]} 0 2
[junit4:junit4] 2> 911788 T2541 C931 P63947 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {add=[10071 (1437889086226432000)]} 0 6
[junit4:junit4] 2> 911790 T2505 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 911790 T2505 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 911796 T2505 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@16aa6e8
[junit4:junit4] 2> 911809 T2505 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=10,adds=10,deletesById=2,deletesByQuery=0,errors=0,cumulative_adds=48,cumulative_deletesById=16,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 911810 T2505 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 911811 T2505 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 911812 T2505 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 911814 T2520 C930 P63935 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={wt=javabin&version=2} {delete=[63 (-1437889086259986432)]} 0 0
[junit4:junit4] 2> 911819 T2505 C932 P63956 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@a89caf lockFactory=org.apache.lucene.store.NativeFSLockFactory@14ed00a),segFN=segments_3,generation=3}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@a89caf lockFactory=org.apache.lucene.store.NativeFSLockFactory@14ed00a),segFN=segments_4,generation=4}
[junit4:junit4] 2> 911820 T2505 C932 P63956 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 4
[junit4:junit4] 2> 911823 T2559 C932 P63956 oasup.LogUpdateProcessor.finish [collection1] webapp=/k_np/sf path=/update params={distrib.from=http://127.0.0.1:63947/k_np/sf/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {} 0 2
[junit4:junit4] 2> 911827 T2559 C932 P63956 oasc.SolrException.log ERROR org.apache.solr.common.SolrException: SolrCoreState already closed
[junit4:junit4] 2> at org.apache.solr.update.DefaultSolrCoreState.getIndexWriter(DefaultSolrCoreState.java:84)
[junit4:junit4] 2> at org.apache.solr.update.DirectUpdateHandler2.delete(DirectUpdateHandler2.java:294)
[junit4:junit4] 2> at org.apache.solr.update.processor.RunUpdateProcessor.processDelete(RunUpdateProcessorFactory.java:77)
[junit4:junit4] 2> at org.apache.solr.update.processor.UpdateRequestProcessor.processDelete(UpdateRequestProcessor.java:55)
[junit4:junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.doLocalDelete(DistributedUpdateProcessor.java:525)
[junit4:junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.versionDelete(DistributedUpdateProcessor.java:1125)
[junit4:junit4] 2> at org.apache.solr.update.processor.DistributedUpdateProcessor.processDelete(DistributedUpdateProcessor.java:787)
[junit4:junit4] 2> at org.apache.solr.update.processor.LogUpdateProcessor.processDelete(LogUpdateProcessorFactory.java:121)
[junit4:junit4] 2> at org.apache.solr.handler.lo
[...truncated too long message...]
: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371279344773 FAILED !!!!!
[junit4:junit4] 2> 2428239 T6890 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 2428244 T6890 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49885 49885
[junit4:junit4] 2> 2429406 T6981 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 2430495 T6981 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 2430498 T6890 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 49892
[junit4:junit4] 2> 2430514 T6890 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 2430515 T6890 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49885 49885
[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=BEDDACF4B8103E18 -Dtests.slow=true -Dtests.locale=pt_BR -Dtests.timezone=US/Michigan -Dtests.file.encoding=Cp1252
[junit4:junit4] ERROR 65.3s | ChaosMonkeyShardSplitTest.testDistribSearch <<<
[junit4:junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:49904 returned non ok status:500, message:Server Error
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([BEDDACF4B8103E18:3F3B22ECCF4F5E24]: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> 2430519 T6890 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> NOTE: test params are: codec=Lucene41, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=pt_BR, timezone=US/Michigan
[junit4:junit4] 2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.7.0_21 (32-bit)/cpus=2,threads=2,free=96445296,total=351076352
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestQuerySenderNoQuery, TestLMDirichletSimilarityFactory, ResourceLoaderTest, SyncSliceTest, TestRangeQuery, TestPerFieldSimilarity, TestRTGBase, ConvertedLegacyTest, TestTrie, ChaosMonkeySafeLeaderTest, SuggesterFSTTest, TestSerializedLuceneMatchVersion, TestRealTimeGet, AutoCommitTest, TestRandomFaceting, SystemInfoHandlerTest, FastVectorHighlighterTest, ResponseLogComponentTest, TestZkChroot, TestManagedSchemaFieldResource, TestPropInject, LeaderElectionTest, TestWordDelimiterFilterFactory, ChaosMonkeyNothingIsSafeTest, FileUtilsTest, TestSweetSpotSimilarityFactory, StatelessScriptUpdateProcessorFactoryTest, DocValuesMultiTest, DistributedQueryElevationComponentTest, BasicZkTest, TestPropInjectDefaults, TestReversedWildcardFilterFactory, TestUtils, OpenCloseCoreStressTest, TestReplicationHandler, PreAnalyzedUpdateProcessorTest, TestMultiCoreConfBootstrap, EchoParamsTest, TestDFRSimilarityFactory, TestDocumentBuilder, ClusterStateUpdateTest, TestArbitraryIndexDir, CoreAdminHandlerTest, TestCodecSupport, DirectSolrSpellCheckerTest, LukeRequestHandlerTest, SuggesterWFSTTest, UniqFieldsUpdateProcessorFactoryTest, LoggingHandlerTest, TestSolrXml, JsonLoaderTest, SpellPossibilityIteratorTest, DebugComponentTest, UUIDFieldTest, PrimUtilsTest, ShowFileRequestHandlerTest, RegexBoostProcessorTest, TermsComponentTest, UnloadDistributedZkTest, TestBinaryResponseWriter, FullSolrCloudDistribCmdsTest, TestHashPartitioner, ShardRoutingCustomTest, SolrIndexConfigTest, TestOmitPositions, RecoveryZkTest, TestSchemaResource, DefaultValueUpdateProcessorTest, TestClassNameShortening, TestIndexingPerformance, TestRecovery, TestFiltering, TestBinaryField, DocumentBuilderTest, MinimalSchemaTest, TestLFUCache, LegacyHTMLStripCharFilterTest, TestJmxMonitoredMap, TestManagedSchema, TestSystemIdResolver, TestGroupingSearch, PreAnalyzedFieldTest, TermVectorComponentDistributedTest, TestIBSimilarityFactory, OpenExchangeRatesOrgProviderTest, TestCloudManagedSchemaAddField, TestLRUCache, TestPseudoReturnFields, NumericFieldsTest, TestFastLRUCache, SoftAutoCommitTest, TestCopyFieldCollectionResource, NoCacheHeaderTest, DirectSolrConnectionTest, TestCollationField, SolrCoreTest, RequestHandlersTest, TestDefaultSimilarityFactory, CachingDirectoryFactoryTest, TestStressLucene, TermVectorComponentTest, TestComponentsName, TestSurroundQueryParser, TestPartialUpdateDeduplication, MoreLikeThisHandlerTest, TestRemoteStreaming, StandardRequestHandlerTest, TestFastWriter, PrimitiveFieldTypeTest, TestIndexSearcher, ClusterStateTest, RAMDirectoryFactoryTest, SliceStateUpdateTest, TestSolrQueryParser, TestCharFilters, TestDocSet, XmlUpdateRequestHandlerTest, BasicDistributedZk2Test, SolrCoreCheckLockOnStartupTest, XsltUpdateRequestHandlerTest, ZkNodePropsTest, BadComponentTest, TestQuerySenderListener, TestMaxScoreQueryParser, LeaderElectionIntegrationTest, TestSchemaSimilarityResource, DisMaxRequestHandlerTest, BinaryUpdateRequestHandlerTest, BasicFunctionalityTest, IndexSchemaRuntimeFieldTest, CSVRequestHandlerTest, CopyFieldTest, PluginInfoTest, TestCSVResponseWriter, DateMathParserTest, TestValueSourceCache, TestFuzzyAnalyzedSuggestions, PathHierarchyTokenizerFactoryTest, TestLazyCores, AnalysisAfterCoreReloadTest, TestUniqueKeyFieldResource, UpdateRequestProcessorFactoryTest, SolrCmdDistributorTest, BasicDistributedZkTest, CollectionsAPIDistributedZkTest, OverseerTest, ShardRoutingTest, ZkSolrClientTest, TestRandomDVFaceting, ZkCLITest, TestDistributedSearch, TestDistributedGrouping, TestFaceting, DistributedSpellCheckComponentTest, ZkControllerTest, TestStressReorder, TestJoin, TestReload, TestStressVersions, HardAutoCommitTest, DistributedTermsComponentTest, TestCoreContainer, SimpleFacetsTest, TestSolr4Spatial, StatsComponentTest, SpellCheckComponentTest, QueryElevationComponentTest, PeerSyncTest, BadIndexSchemaTest, TestSort, TestFunctionQuery, DirectUpdateHandlerTest, TestBadConfig, OverseerCollectionProcessorTest, HighlighterTest, CurrencyFieldOpenExchangeTest, CurrencyFieldXmlFileTest, SolrIndexSplitterTest, SimplePostToolTest, TestCoreDiscovery, SignatureUpdateProcessorFactoryTest, TestExtendedDismaxParser, SpellCheckCollatorTest, SolrRequestParserTest, TestFoldingMultitermQuery, DocValuesTest, SuggesterTSTTest, SuggesterTest, SpatialFilterTest, TestCSVLoader, PolyFieldTest, WordBreakSolrSpellCheckerTest, SchemaVersionSpecificBehaviorTest, TestUpdate, FieldMutatingUpdateProcessorTest, TestAtomicUpdateErrorCases, QueryEqualityTest, DirectUpdateHandlerOptimizeTest, SortByFunctionTest, DistanceFunctionTest, TestSolrDeletionPolicy1, SolrInfoMBeanTest, CacheHeaderTest, IndexBasedSpellCheckerTest, TestQueryUtils, TestWriterPerf, DocumentAnalysisRequestHandlerTest, TestQueryTypes, FileBasedSpellCheckerTest, RequiredFieldsTest, FieldAnalysisRequestHandlerTest, SolrPluginUtilsTest, IndexSchemaTest, TestJmxIntegration, ReturnFieldsTest, JSONWriterTest, MBeansHandlerTest, QueryParsingTest, TestAnalyzedSuggestions, TestPHPSerializedResponseWriter, PingRequestHandlerTest, SearchHandlerTest, CoreContainerCoreInitFailuresTest, HighlighterConfigTest, SOLR749Test, IndexReaderFactoryTest, UpdateParamsTest, AlternateDirectoryTest, TestSolrIndexConfig, TestStressRecovery, TestMergePolicyConfig, TestSolrDeletionPolicy2, MultiTermTest, SampleTest, TestSearchPerf, TestElisionMultitermQuery, TestConfig, OutputWriterTest, ExternalFileFieldSortTest, TestSolrCoreProperties, TestPostingsSolrHighlighter, NotRequiredUniqueKeyTest, TestLuceneMatchVersion, TestPhraseSuggestions, SynonymTokenizerTest, TestXIncludeConfig, TestNumberUtils, TestLMJelinekMercerSimilarityFactory, TestBM25SimilarityFactory, TestPluginEnable, TimeZoneUtilsTest, TestFastOutputStream, ScriptEngineTest, URLClassifyProcessorTest, TestSolrXMLSerializer, TestSuggestSpellingConverter, DateFieldTest, SpellingQueryConverterTest, DOMUtilTest, TestSolrJ, SliceStateTest, CircularListTest, SolrTestCaseJ4Test, TestCollationKeyRangeQueries, AliasIntegrationTest, ChaosMonkeyShardSplitTest]
[junit4:junit4] Completed in 65.37s, 1 test, 1 error <<< FAILURES!
[...truncated 65 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:391: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:371: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build.xml:181: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\common-build.xml:437: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1243: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:887: There were test failures: 297 suites, 1246 tests, 1 error, 1 failure, 18 ignored (12 assumptions)
Total time: 66 minutes 30 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_21 -server -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure