You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/06/22 07:09:05 UTC
[JENKINS] Lucene-Solr-4.x-Windows (64bit/jdk1.7.0_25) - Build #
2917 - Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/2917/
Java: 64bit/jdk1.7.0_25 -XX:+UseCompressedOops -XX:+UseParallelGC
3 tests failed.
REGRESSION: org.apache.solr.cloud.ShardSplitTest.testDistribSearch
Error Message:
Server at http://127.0.0.1:56616 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:56616 returned non ok status:500, message:Server Error
at __randomizedtesting.SeedInfo.seed([99B7F739742481F1:18517921037BE1CD]: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.ShardSplitTest.doTest(ShardSplitTest.java:150)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
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:606)
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:724)
REGRESSION: org.apache.solr.cloud.SyncSliceTest.testDistribSearch
Error Message:
shard1 is not consistent. Got 305 from http://127.0.0.1:58739/kk_ru/ob/collection1lastClient and got 252 from http://127.0.0.1:58758/kk_ru/ob/collection1
Stack Trace:
java.lang.AssertionError: shard1 is not consistent. Got 305 from http://127.0.0.1:58739/kk_ru/ob/collection1lastClient and got 252 from http://127.0.0.1:58758/kk_ru/ob/collection1
at __randomizedtesting.SeedInfo.seed([99B7F739742481F1:18517921037BE1CD]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.cloud.AbstractFullDistribZkTestBase.checkShardConsistency(AbstractFullDistribZkTestBase.java:1018)
at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:238)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
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:606)
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:724)
FAILED: org.apache.solr.core.TestSolrXmlPersistence.testCreateAndManipulateCores
Error Message:
File XPath failure: file=.\org.apache.solr.core.TestSolrXmlPersistence\create_man_1.xml xpath=/solr/cores/core[@name='new_two' and @instanceDir='new_two/'] xml was: <?xml version="1.0" encoding="UTF-8" ?> <solr coreLoadThreads="12" persistent="${solr.xml.persist:false}" sharedLib="${something:.}"> <logging enabled="{logenable:true}" class="${logclass:log4j.class}"> <watcher threshold="${logThresh:54}" size="{watchSize:13}"/> </logging> <shardHandlerFactory name="${shhandler:shardHandlerFactory}" class="${handlefac:HttpShardHandlerFactory}"> <int name="connTimeout">${connTimeout:15000}</int> <int name="socketTimeout">${socketTimeout:120000}</int> </shardHandlerFactory> <cores transientCacheSize="${tranSize:128}" defaultCoreName="SystemVars1" host="127.0.0.1" adminPath="/admin/cores" leaderVoteWait="${leadVoteWait:32}" shareSchema="${shareSchema:false}" zkClientTimeout="${solr.zkclienttimeout:30000}" distribUpdateSoTimeout="${distribUpdateSoTimeout:120000}" distribUpdateConnTimeout="${distribUpdateConnTimeout:15000}" hostPort="${hostPort:8983}" hostContext="${hostContext:solr}" managementPath="${manpath:/var/lib/path}"> <core schema="${schema:schema.xml}" shard="${shard:32}" coreNodeName="${coreNodeName:}" instanceDir="SystemVars2" name="SystemVars2" config="${solrconfig:solrconfig.xml}" collection="${collection:collection2}"> <property name="schema" value="${schema:schema.xml}"/> <property name="collection" value="{collection:collection2}"/> <property name="coreNodeName" value="EricksCore"/> </core> <core instanceDir="C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.core.TestSolrXmlPersistence\new_one" name="new_one"/> <core instanceDir="new_two\" name="new_two"/> <core schema="${schema:schema.xml}" loadOnStartup="${onStart:true}" shard="${shard:32}" coreNodeName="${coreNode:utterlyridiculous}" instanceDir="SystemVars1" roles="${myrole:boss}" transient="${tran:true}" name="SystemVars1" config="${solrconfig:solrconfig.xml}" dataDir="${data:./}" collection="${collection:collection1}" ulogDir="${ulog:./}"/> </cores> </solr>
Stack Trace:
java.lang.AssertionError: File XPath failure: file=.\org.apache.solr.core.TestSolrXmlPersistence\create_man_1.xml xpath=/solr/cores/core[@name='new_two' and @instanceDir='new_two/']
xml was: <?xml version="1.0" encoding="UTF-8" ?>
<solr coreLoadThreads="12" persistent="${solr.xml.persist:false}" sharedLib="${something:.}">
<logging enabled="{logenable:true}" class="${logclass:log4j.class}">
<watcher threshold="${logThresh:54}" size="{watchSize:13}"/>
</logging>
<shardHandlerFactory name="${shhandler:shardHandlerFactory}" class="${handlefac:HttpShardHandlerFactory}">
<int name="connTimeout">${connTimeout:15000}</int>
<int name="socketTimeout">${socketTimeout:120000}</int>
</shardHandlerFactory>
<cores transientCacheSize="${tranSize:128}" defaultCoreName="SystemVars1" host="127.0.0.1" adminPath="/admin/cores" leaderVoteWait="${leadVoteWait:32}" shareSchema="${shareSchema:false}" zkClientTimeout="${solr.zkclienttimeout:30000}" distribUpdateSoTimeout="${distribUpdateSoTimeout:120000}" distribUpdateConnTimeout="${distribUpdateConnTimeout:15000}" hostPort="${hostPort:8983}" hostContext="${hostContext:solr}" managementPath="${manpath:/var/lib/path}">
<core schema="${schema:schema.xml}" shard="${shard:32}" coreNodeName="${coreNodeName:}" instanceDir="SystemVars2" name="SystemVars2" config="${solrconfig:solrconfig.xml}" collection="${collection:collection2}">
<property name="schema" value="${schema:schema.xml}"/>
<property name="collection" value="{collection:collection2}"/>
<property name="coreNodeName" value="EricksCore"/>
</core>
<core instanceDir="C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.core.TestSolrXmlPersistence\new_one" name="new_one"/>
<core instanceDir="new_two\" name="new_two"/>
<core schema="${schema:schema.xml}" loadOnStartup="${onStart:true}" shard="${shard:32}" coreNodeName="${coreNode:utterlyridiculous}" instanceDir="SystemVars1" roles="${myrole:boss}" transient="${tran:true}" name="SystemVars1" config="${solrconfig:solrconfig.xml}" dataDir="${data:./}" collection="${collection:collection1}" ulogDir="${ulog:./}"/>
</cores>
</solr>
at __randomizedtesting.SeedInfo.seed([99B7F739742481F1:88997CBDB90458B9]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.apache.solr.SolrTestCaseJ4.assertXmlFile(SolrTestCaseJ4.java:1458)
at org.apache.solr.core.TestSolrXmlPersistence.testCreateAndManipulateCores(TestSolrXmlPersistence.java:375)
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:606)
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:724)
Build Log:
[...truncated 9277 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.ShardSplitTest
[junit4:junit4] 2> 51201 T162 oas.SolrTestCaseJ4.startTrackingSearchers WARN startTrackingSearchers: numOpens=1 numCloses=1
[junit4:junit4] 2> 51203 T162 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4] 2> 51213 T162 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-ShardSplitTest-1371875180548
[junit4:junit4] 2> 51226 T162 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 51235 T163 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 51452 T162 oasc.ZkTestServer.run start zk server on port:56597
[junit4:junit4] 2> 51654 T162 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 51764 T169 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@78527518 name:ZooKeeperConnection Watcher:127.0.0.1:56597 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 51765 T162 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 51774 T162 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 51875 T162 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 51879 T171 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@67fcee4a name:ZooKeeperConnection Watcher:127.0.0.1:56597/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 51879 T162 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 51883 T162 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 51894 T162 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 51903 T162 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 51912 T162 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 51921 T162 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> 51942 T162 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 51958 T162 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\schema15.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 51960 T162 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 51972 T162 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> 51973 T162 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 51983 T162 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> 51985 T162 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 51995 T162 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> 51997 T162 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 52008 T162 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> 52009 T162 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 52017 T162 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> 52017 T162 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 52027 T162 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> 52029 T162 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 52037 T162 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> 52037 T162 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 52507 T162 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 52513 T162 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:56604
[junit4:junit4] 2> 52514 T162 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 52515 T162 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 52515 T162 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.ShardSplitTest-controljetty-1371875181382
[junit4:junit4] 2> 52516 T162 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.ShardSplitTest-controljetty-1371875181382\solr.xml
[junit4:junit4] 2> 52517 T162 oasc.CoreContainer.<init> New CoreContainer 431869431
[junit4:junit4] 2> 52517 T162 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.ShardSplitTest-controljetty-1371875181382\'
[junit4:junit4] 2> 52518 T162 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.ShardSplitTest-controljetty-1371875181382\'
[junit4:junit4] 2> 52638 T162 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 52638 T162 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 52641 T162 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 52641 T162 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 52641 T162 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 52642 T162 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 52643 T162 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 52643 T162 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 52645 T162 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 52645 T162 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 52659 T162 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 52660 T162 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:56597/solr
[junit4:junit4] 2> 52686 T162 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 52688 T162 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 52702 T182 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@397c8a21 name:ZooKeeperConnection Watcher:127.0.0.1:56597 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 52703 T162 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 52708 T164 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13f6a2201600002, 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:724)
[junit4:junit4] 2>
[junit4:junit4] 2> 52712 T162 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 52734 T162 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 52739 T184 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2d2d1d47 name:ZooKeeperConnection Watcher:127.0.0.1:56597/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 52739 T162 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 52756 T162 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 52778 T162 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 52799 T162 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 52805 T162 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56604_
[junit4:junit4] 2> 52813 T162 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:56604_
[junit4:junit4] 2> 52823 T162 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 52851 T162 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 52858 T162 oasc.Overseer.start Overseer (id=89907211855200259-127.0.0.1:56604_-n_0000000000) starting
[junit4:junit4] 2> 52881 T162 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 52902 T186 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 52903 T162 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 52911 T162 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 52918 T162 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 52939 T185 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 52955 T187 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 52955 T187 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 54570 T185 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 54573 T185 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:56604_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:56604"}
[junit4:junit4] 2> 54573 T185 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 54599 T185 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 54632 T184 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> 55115 T187 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.ShardSplitTest-controljetty-1371875181382\collection1
[junit4:junit4] 2> 55115 T187 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 55118 T187 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 55118 T187 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 55122 T187 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.ShardSplitTest-controljetty-1371875181382\collection1\'
[junit4:junit4] 2> 55124 T187 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1371875181382/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 55126 T187 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1371875181382/collection1/lib/README' to classloader
[junit4:junit4] 2> 55216 T187 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 55301 T187 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 55305 T187 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 55315 T187 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 55943 T187 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 55947 T187 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 55951 T187 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 55960 T187 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 56186 T187 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 56187 T187 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.ShardSplitTest-controljetty-1371875181382\collection1\, dataDir=.\org.apache.solr.cloud.ShardSplitTest-1371875180547/control/data\
[junit4:junit4] 2> 56187 T187 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3264c826
[junit4:junit4] 2> 56187 T187 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 56188 T187 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1371875180547/control/data\
[junit4:junit4] 2> 56188 T187 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardSplitTest-1371875180547/control/data\index/
[junit4:junit4] 2> 56188 T187 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ShardSplitTest-1371875180547\control\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 56189 T187 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1371875180547/control/data\index
[junit4:junit4] 2> 56195 T187 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@66db9181 lockFactory=org.apache.lucene.store.NativeFSLockFactory@66d04849),segFN=segments_1,generation=1}
[junit4:junit4] 2> 56195 T187 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 56199 T187 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 56199 T187 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 56200 T187 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 56200 T187 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 56201 T187 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 56201 T187 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 56202 T187 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 56202 T187 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 56203 T187 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 56212 T187 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 56219 T187 oass.SolrIndexSearcher.<init> Opening Searcher@20f796ee main
[junit4:junit4] 2> 56220 T187 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.ShardSplitTest-1371875180547\control\data\tlog
[junit4:junit4] 2> 56222 T187 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 56222 T187 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 56225 T188 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@20f796ee main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 56227 T187 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 56227 T187 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:56604 collection:control_collection shard:shard1
[junit4:junit4] 2> 56237 T187 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4:junit4] 2> 56246 T187 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 56271 T187 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 56279 T187 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 56279 T187 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 56280 T187 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:56604/collection1/
[junit4:junit4] 2> 56280 T187 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 56280 T187 oasc.SyncStrategy.syncToMe http://127.0.0.1:56604/collection1/ has no replicas
[junit4:junit4] 2> 56280 T187 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:56604/collection1/
[junit4:junit4] 2> 56281 T187 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 57883 T185 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 57910 T184 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> 57945 T187 oasc.ZkController.register We are http://127.0.0.1:56604/collection1/ and leader is http://127.0.0.1:56604/collection1/
[junit4:junit4] 2> 57945 T187 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:56604
[junit4:junit4] 2> 57945 T187 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 57946 T187 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 57946 T187 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 57951 T187 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 57953 T162 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 57953 T162 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 57954 T162 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 57960 T162 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 57967 T162 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 57972 T191 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@630f64d4 name:ZooKeeperConnection Watcher:127.0.0.1:56597/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 57972 T162 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 57975 T162 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 57983 T162 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 58403 T162 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 58408 T162 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:56616
[junit4:junit4] 2> 58409 T162 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 58410 T162 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 58410 T162 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.ShardSplitTest-jetty1-1371875187317
[junit4:junit4] 2> 58411 T162 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.ShardSplitTest-jetty1-1371875187317\solr.xml
[junit4:junit4] 2> 58412 T162 oasc.CoreContainer.<init> New CoreContainer 607321090
[junit4:junit4] 2> 58413 T162 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.ShardSplitTest-jetty1-1371875187317\'
[junit4:junit4] 2> 58414 T162 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.ShardSplitTest-jetty1-1371875187317\'
[junit4:junit4] 2> 58529 T162 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 58530 T162 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 58530 T162 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 58530 T162 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 58531 T162 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 58531 T162 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 58531 T162 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 58532 T162 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 58532 T162 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 58533 T162 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 58540 T162 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 58541 T162 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:56597/solr
[junit4:junit4] 2> 58541 T162 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 58544 T162 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 58561 T202 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13b25934 name:ZooKeeperConnection Watcher:127.0.0.1:56597 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 58562 T162 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 58567 T162 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 58568 T164 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13f6a2201600005, 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:724)
[junit4:junit4] 2>
[junit4:junit4] 2> 58583 T162 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 58594 T204 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5cb3d841 name:ZooKeeperConnection Watcher:127.0.0.1:56597/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 58594 T162 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 58605 T162 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 59484 T185 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 59486 T185 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:56604__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:56604_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:56604"}
[junit4:junit4] 2> 59499 T204 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> 59500 T184 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> 59500 T191 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> 59620 T162 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56616_
[junit4:junit4] 2> 59625 T162 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:56616_
[junit4:junit4] 2> 59632 T191 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> 59635 T204 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 59635 T204 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> 59636 T184 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 59637 T184 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> 59644 T191 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 59657 T205 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 59658 T205 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 61012 T185 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 61014 T185 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[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:56616_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:56616"}
[junit4:junit4] 2> 61014 T185 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 61014 T185 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 61035 T184 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> 61036 T204 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> 61036 T191 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> 61661 T205 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.ShardSplitTest-jetty1-1371875187317\collection1
[junit4:junit4] 2> 61661 T205 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 61662 T205 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 61663 T205 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 61666 T205 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.ShardSplitTest-jetty1-1371875187317\collection1\'
[junit4:junit4] 2> 61667 T205 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1371875187317/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 61668 T205 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1371875187317/collection1/lib/README' to classloader
[junit4:junit4] 2> 61719 T205 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 61782 T205 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 61785 T205 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 61792 T205 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 62354 T205 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 62358 T205 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 62360 T205 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 62368 T205 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 62422 T205 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 62423 T205 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.ShardSplitTest-jetty1-1371875187317\collection1\, dataDir=.\org.apache.solr.cloud.ShardSplitTest-1371875180547/jetty1\
[junit4:junit4] 2> 62423 T205 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3264c826
[junit4:junit4] 2> 62424 T205 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 62424 T205 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1371875180547/jetty1\
[junit4:junit4] 2> 62425 T205 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardSplitTest-1371875180547/jetty1\index/
[junit4:junit4] 2> 62425 T205 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ShardSplitTest-1371875180547\jetty1\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 62426 T205 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1371875180547/jetty1\index
[junit4:junit4] 2> 62429 T205 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@49b328a lockFactory=org.apache.lucene.store.NativeFSLockFactory@11a390fc),segFN=segments_1,generation=1}
[junit4:junit4] 2> 62429 T205 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 62433 T205 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 62434 T205 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 62434 T205 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 62435 T205 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 62436 T205 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 62436 T205 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 62436 T205 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 62438 T205 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 62439 T205 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 62451 T205 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 62459 T205 oass.SolrIndexSearcher.<init> Opening Searcher@1d30c140 main
[junit4:junit4] 2> 62460 T205 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.ShardSplitTest-1371875180547\jetty1\tlog
[junit4:junit4] 2> 62462 T205 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 62463 T205 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 62468 T206 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1d30c140 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 62470 T205 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 62471 T205 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:56616 collection:collection1 shard:shard1
[junit4:junit4] 2> 62472 T205 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 62495 T205 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 62502 T205 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 62502 T205 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 62503 T205 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:56616/collection1/
[junit4:junit4] 2> 62503 T205 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 62503 T205 oasc.SyncStrategy.syncToMe http://127.0.0.1:56616/collection1/ has no replicas
[junit4:junit4] 2> 62504 T205 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:56616/collection1/
[junit4:junit4] 2> 62504 T205 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 62551 T185 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 62579 T184 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> 62580 T204 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> 62581 T191 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> 62622 T205 oasc.ZkController.register We are http://127.0.0.1:56616/collection1/ and leader is http://127.0.0.1:56616/collection1/
[junit4:junit4] 2> 62622 T205 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:56616
[junit4:junit4] 2> 62622 T205 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 62623 T205 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 62623 T205 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 62629 T205 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 62631 T162 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 62632 T162 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 62632 T162 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 63029 T162 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 63033 T162 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:56625
[junit4:junit4] 2> 63034 T162 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 63034 T162 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 63035 T162 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.ShardSplitTest-jetty2-1371875191973
[junit4:junit4] 2> 63035 T162 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.ShardSplitTest-jetty2-1371875191973\solr.xml
[junit4:junit4] 2> 63036 T162 oasc.CoreContainer.<init> New CoreContainer 2040397133
[junit4:junit4] 2> 63036 T162 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.ShardSplitTest-jetty2-1371875191973\'
[junit4:junit4] 2> 63037 T162 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.ShardSplitTest-jetty2-1371875191973\'
[junit4:junit4] 2> 63147 T162 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 63148 T162 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 63148 T162 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 63148 T162 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 63149 T162 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 63149 T162 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 63149 T162 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 63149 T162 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 63149 T162 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 63150 T162 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 63159 T162 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 63160 T162 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:56597/solr
[junit4:junit4] 2> 63160 T162 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 63162 T162 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 63177 T218 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@23fef4b5 name:ZooKeeperConnection Watcher:127.0.0.1:56597 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 63177 T162 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 63181 T162 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 63190 T162 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 63195 T220 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11daa417 name:ZooKeeperConnection Watcher:127.0.0.1:56597/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 63195 T162 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 63205 T162 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 64105 T185 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 64106 T185 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:56616__collection1",
[junit4:junit4] 2> "numShards":"2",
[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:56616_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:56616"}
[junit4:junit4] 2> 64122 T191 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> 64122 T220 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> 64122 T204 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> 64123 T184 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> 64212 T162 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56625_
[junit4:junit4] 2> 64218 T162 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:56625_
[junit4:junit4] 2> 64226 T191 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> 64228 T204 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 64229 T204 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> 64230 T184 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 64230 T184 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> 64231 T220 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 64231 T220 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> 64240 T191 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 64251 T221 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 64251 T221 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 65641 T185 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 65643 T185 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[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:56625_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:56625"}
[junit4:junit4] 2> 65643 T185 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 65643 T185 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 65662 T191 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> 65662 T220 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> 65662 T184 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> 65662 T204 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> 66254 T221 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.ShardSplitTest-jetty2-1371875191973\collection1
[junit4:junit4] 2> 66254 T221 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 66255 T221 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 66256 T221 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 66259 T221 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.ShardSplitTest-jetty2-1371875191973\collection1\'
[junit4:junit4] 2> 66260 T221 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1371875191973/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 66261 T221 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1371875191973/collection1/lib/README' to classloader
[junit4:junit4] 2> 66312 T221 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 66373 T221 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 66378 T221 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 66384 T221 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 66958 T221 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 66962 T221 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 66964 T221 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 66970 T221 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 67022 T221 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 67022 T221 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.ShardSplitTest-jetty2-1371875191973\collection1\, dataDir=.\org.apache.solr.cloud.ShardSplitTest-1371875180547/jetty2\
[junit4:junit4] 2> 67023 T221 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3264c826
[junit4:junit4] 2> 67023 T221 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 67025 T221 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1371875180547/jetty2\
[junit4:junit4] 2> 67025 T221 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardSplitTest-1371875180547/jetty2\index/
[junit4:junit4] 2> 67025 T221 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ShardSplitTest-1371875180547\jetty2\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 67025 T221 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1371875180547/jetty2\index
[junit4:junit4] 2> 67030 T221 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@156b2796 lockFactory=org.apache.lucene.store.NativeFSLockFactory@42d66ff5),segFN=segments_1,generation=1}
[junit4:junit4] 2> 67030 T221 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 67034 T221 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 67034 T221 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 67035 T221 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 67036 T221 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 67037 T221 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 67037 T221 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 67038 T221 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 67038 T221 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 67039 T221 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 67049 T221 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 67056 T221 oass.SolrIndexSearcher.<init> Opening Searcher@3c1544d6 main
[junit4:junit4] 2> 67057 T221 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.ShardSplitTest-1371875180547\jetty2\tlog
[junit4:junit4] 2> 67059 T221 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 67059 T221 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 67064 T222 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3c1544d6 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 67067 T221 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 67068 T221 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:56625 collection:collection1 shard:shard2
[junit4:junit4] 2> 67070 T221 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 67094 T221 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 67103 T221 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 67103 T221 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 67103 T221 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:56625/collection1/
[junit4:junit4] 2> 67104 T221 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 67104 T221 oasc.SyncStrategy.syncToMe http://127.0.0.1:56625/collection1/ has no replicas
[junit4:junit4] 2> 67104 T221 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:56625/collection1/
[junit4:junit4] 2> 67104 T221 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 67181 T185 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 67207 T204 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> 67207 T191 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> 67207 T220 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> 67207 T184 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> 67221 T221 oasc.ZkController.register We are http://127.0.0.1:56625/collection1/ and leader is http://127.0.0.1:56625/collection1/
[junit4:junit4] 2> 67221 T221 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:56625
[junit4:junit4] 2> 67221 T221 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 67222 T221 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 67222 T221 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 67227 T221 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 67229 T162 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 67229 T162 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 67229 T162 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 67645 T162 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 67649 T162 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:56634
[junit4:junit4] 2> 67650 T162 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 67651 T162 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 67651 T162 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.ShardSplitTest-jetty3-1371875196572
[junit4:junit4] 2> 67651 T162 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.ShardSplitTest-jetty3-1371875196572\solr.xml
[junit4:junit4] 2> 67652 T162 oasc.CoreContainer.<init> New CoreContainer 636789956
[junit4:junit4] 2> 67652 T162 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.ShardSplitTest-jetty3-1371875196572\'
[junit4:junit4] 2> 67653 T162 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.ShardSplitTest-jetty3-1371875196572\'
[junit4:junit4] 2> 67779 T162 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 67779 T162 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 67780 T162 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 67780 T162 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 67780 T162 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 67780 T162 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 67781 T162 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 67782 T162 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 67782 T162 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 67783 T162 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 67791 T162 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 67792 T162 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:56597/solr
[junit4:junit4] 2> 67793 T162 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 67795 T162 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 67812 T234 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7ce0d250 name:ZooKeeperConnection Watcher:127.0.0.1:56597 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 67813 T162 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 67818 T162 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 67826 T162 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 67831 T236 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10755569 name:ZooKeeperConnection Watcher:127.0.0.1:56597/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 67831 T162 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 67841 T162 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 68723 T185 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 68725 T185 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:56625__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:56625_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:56625"}
[junit4:junit4] 2> 68742 T191 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> 68743 T184 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> 68743 T220 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> 68742 T204 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> 68743 T236 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> 68847 T162 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56634_
[junit4:junit4] 2> 68850 T162 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:56634_
[junit4:junit4] 2> 68855 T191 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> 68861 T236 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 68861 T236 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 68863 T184 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 68863 T184 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 68863 T204 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 68863 T204 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 68864 T220 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 68864 T220 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 68874 T191 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 68890 T237 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 68890 T237 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 70255 T185 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 70256 T185 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[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:56634_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:56634"}
[junit4:junit4] 2> 70257 T185 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 70257 T185 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 70270 T204 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 70270 T236 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 70271 T184 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 70270 T191 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 70272 T220 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 70894 T237 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.ShardSplitTest-jetty3-1371875196572\collection1
[junit4:junit4] 2> 70894 T237 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 70896 T237 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 70896 T237 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 70900 T237 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.ShardSplitTest-jetty3-1371875196572\collection1\'
[junit4:junit4] 2> 70901 T237 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1371875196572/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 70902 T237 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1371875196572/collection1/lib/README' to classloader
[junit4:junit4] 2> 70958 T237 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 71017 T237 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 71021 T237 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 71029 T237 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 71592 T237 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 71595 T237 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 71598 T237 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 71604 T237 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 71673 T237 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 71674 T237 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.ShardSplitTest-jetty3-1371875196572\collection1\, dataDir=.\org.apache.solr.cloud.ShardSplitTest-1371875180547/jetty3\
[junit4:junit4] 2> 71674 T237 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3264c826
[junit4:junit4] 2> 71674 T237 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 71675 T237 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1371875180547/jetty3\
[junit4:junit4] 2> 71675 T237 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardSplitTest-1371875180547/jetty3\index/
[junit4:junit4] 2> 71675 T237 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ShardSplitTest-1371875180547\jetty3\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 71676 T237 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1371875180547/jetty3\index
[junit4:junit4] 2> 71680 T237 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@383bd328 lockFactory=org.apache.lucene.store.NativeFSLockFactory@78aa6cbd),segFN=segments_1,generation=1}
[junit4:junit4] 2> 71680 T237 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 71684 T237 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 71685 T237 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 71685 T237 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 71686 T237 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 71687 T237 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 71687 T237 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 71688 T237 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 71688 T237 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 71689 T237 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 71699 T237 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 71706 T237 oass.SolrIndexSearcher.<init> Opening Searcher@66c9f0e7 main
[junit4:junit4] 2> 71707 T237 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.ShardSplitTest-1371875180547\jetty3\tlog
[junit4:junit4] 2> 71709 T237 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 71709 T237 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 71716 T238 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@66c9f0e7 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 71718 T237 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 71718 T237 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:56634 collection:collection1 shard:shard1
[junit4:junit4] 2> 71729 T237 oasc.ZkController.register We are http://127.0.0.1:56634/collection1/ and leader is http://127.0.0.1:56616/collection1/
[junit4:junit4] 2> 71730 T237 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:56634
[junit4:junit4] 2> 71730 T237 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 71730 T237 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C33 name=collection1 org.apache.solr.core.SolrCore@64bbe1ee url=http://127.0.0.1:56634/collection1 node=127.0.0.1:56634_ C33_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:56634_, base_url=http://127.0.0.1:56634}
[junit4:junit4] 2> 71737 T239 C33 P56634 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 71738 T239 C33 P56634 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 71738 T239 C33 P56634 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 71738 T239 C33 P56634 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 71738 T237 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 71742 T239 C33 P56634 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 71744 T162 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 71744 T162 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 71744 T162 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 71765 T198 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:56634__collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 71788 T185 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 71789 T185 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:56634__collection1",
[junit4:junit4] 2> "numShards":"2",
[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:56634_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:56634"}
[junit4:junit4] 2> 71812 T204 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 71813 T236 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 71813 T184 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 71814 T220 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 71814 T191 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 72144 T162 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 72148 T162 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:56644
[junit4:junit4] 2> 72149 T162 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 72149 T162 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 72150 T162 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.ShardSplitTest-jetty4-1371875201084
[junit4:junit4] 2> 72150 T162 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.ShardSplitTest-jetty4-1371875201084\solr.xml
[junit4:junit4] 2> 72150 T162 oasc.CoreContainer.<init> New CoreContainer 558262585
[junit4:junit4] 2> 72151 T162 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.ShardSplitTest-jetty4-1371875201084\'
[junit4:junit4] 2> 72152 T162 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.ShardSplitTest-jetty4-1371875201084\'
[junit4:junit4] 2> 72254 T162 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 72254 T162 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 72254 T162 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 72256 T162 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 72256 T162 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 72256 T162 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 72256 T162 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 72256 T162 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 72257 T162 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 72257 T162 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 72265 T162 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 72265 T162 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:56597/solr
[junit4:junit4] 2> 72265 T162 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 72268 T162 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 72282 T251 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5ccfd847 name:ZooKeeperConnection Watcher:127.0.0.1:56597 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 72283 T162 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 72290 T162 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 72296 T162 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 72301 T253 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@23c9e065 name:ZooKeeperConnection Watcher:127.0.0.1:56597/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 72302 T162 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 72313 T162 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 72765 T198 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:56634__collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 72765 T198 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:56634__collection1&state=recovering&nodeName=127.0.0.1:56634_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1004
[junit4:junit4] 2> 73320 T162 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:56644_
[junit4:junit4] 2> 73337 T162 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:56644_
[junit4:junit4] 2> 73364 T191 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 73368 T204 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 73369 T204 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 73371 T253 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 73368 T236 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 73371 T236 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 73376 T220 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 73376 T220 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 73378 T184 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 73379 T184 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 73386 T191 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 73396 T254 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 73397 T254 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> C33_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:56634_, base_url=http://127.0.0.1:56634}
[junit4:junit4] 2> 74766 T239 C33 P56634 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:56616/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 74767 T239 C33 P56634 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:56634 START replicas=[http://127.0.0.1:56616/collection1/] nUpdates=100
[junit4:junit4] 2> 74768 T239 C33 P56634 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 74770 T239 C33 P56634 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 74770 T239 C33 P56634 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 74771 T239 C33 P56634 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 74771 T239 C33 P56634 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 74773 T239 C33 P56634 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:56616/collection1/. core=collection1
[junit4:junit4] 2> 74773 T239 C33 P56634 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C34 name=collection1 org.apache.solr.core.SolrCore@663afdd8 url=http://127.0.0.1:56616/collection1 node=127.0.0.1:56616_ C34_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:56616_, base_url=http://127.0.0.1:56616, leader=true}
[junit4:junit4] 2> 74790 T198 C34 P56616 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 2> 74821 T195 C34 P56616 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 74829 T195 C34 P56616 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@49b328a lockFactory=org.apache.lucene.store.NativeFSLockFactory@11a390fc),segFN=segments_1,generation=1}
[junit4:junit4] 2> 74831 T195 C34 P56616 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 74832 T195 C34 P56616 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@49b328a lockFactory=org.apache.lucene.store.NativeFSLockFactory@11a390fc),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@49b328a lockFactory=org.apache.lucene.store.NativeFSLockFactory@11a390fc),segFN=segments_2,generation=2}
[junit4:junit4] 2> 74832 T195 C34 P56616 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 74833 T195 C34 P56616 oass.SolrIndexSearcher.<init> Opening Searcher@1566ee23 realtime
[junit4:junit4] 2> 74833 T195 C34 P56616 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 74833 T195 C34 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 40
[junit4:junit4] 2> 74847 T185 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 74849 T185 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[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:56644_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:56644"}
[junit4:junit4] 2> 74849 T185 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 74849 T185 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 74866 T253 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 74867 T191 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 74868 T204 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 74869 T236 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 74869 T184 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 74870 T220 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 74883 T239 C33 P56634 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 74883 T239 C33 P56634 oascsi.HttpClientUtil.createClient Creating new http client, config:connTimeout=5000&socketTimeout=20000&allowCompression=false&maxConnections=10000&maxConnectionsPerHost=10000
[junit4:junit4] 2> 74893 T239 C33 P56634 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 74897 T199 C34 P56616 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 74898 T199 C34 P56616 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=2
[junit4:junit4] 2> 74900 T239 C33 P56634 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 74900 T239 C33 P56634 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 74900 T239 C33 P56634 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 74904 T200 C34 P56616 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=1
[junit4:junit4] 2> 74905 T239 C33 P56634 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 74906 T239 C33 P56634 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1371875180547/jetty3\index.20130622072644238
[junit4:junit4] 2> 74906 T239 C33 P56634 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@6208e5ba lockFactory=org.apache.lucene.store.NativeFSLockFactory@55ed0c10) fullCopy=false
[junit4:junit4] 2> 74919 T198 C34 P56616 oasc.SolrCore.execute [collection1] webapp= path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=5
[junit4:junit4] 2> 74934 T239 C33 P56634 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 74936 T239 C33 P56634 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 74936 T239 C33 P56634 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 74944 T239 C33 P56634 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@383bd328 lockFactory=org.apache.lucene.store.NativeFSLockFactory@78aa6cbd),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@383bd328 lockFactory=org.apache.lucene.store.NativeFSLockFactory@78aa6cbd),segFN=segments_2,generation=2}
[junit4:junit4] 2> 74945 T239 C33 P56634 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 74945 T239 C33 P56634 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 74945 T239 C33 P56634 oass.SolrIndexSearcher.<init> Opening Searcher@64e4cdb main
[junit4:junit4] 2> 74946 T238 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@64e4cdb main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 74947 T239 C33 P56634 oasc.CachingDirectoryFactory.closeCacheValue looking to close .\org.apache.solr.cloud.ShardSplitTest-1371875180547/jetty3\index.20130622072644238 [CachedDir<<refCount=0;path=.\org.apache.solr.cloud.ShardSplitTest-1371875180547/jetty3\index.20130622072644238;done=true>>]
[junit4:junit4] 2> 74947 T239 C33 P56634 oasc.CachingDirectoryFactory.close Closing directory: .\org.apache.solr.cloud.ShardSplitTest-1371875180547/jetty3\index.20130622072644238
[junit4:junit4] 2> 74947 T239 C33 P56634 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: .\org.apache.solr.cloud.ShardSplitTest-1371875180547/jetty3\index.20130622072644238
[junit4:junit4] 2> 74947 T239 C33 P56634 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 74948 T239 C33 P56634 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 74948 T239 C33 P56634 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 74948 T239 C33 P56634 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 74953 T239 C33 P56634 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 75401 T254 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.ShardSplitTest-jetty4-1371875201084\collection1
[junit4:junit4] 2> 75401 T254 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 75403 T254 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 75403 T254 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 75410 T254 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.ShardSplitTest-jetty4-1371875201084\collection1\'
[junit4:junit4] 2> 75416 T254 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty4-1371875201084/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 75419 T254 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty4-1371875201084/collection1/lib/README' to classloader
[junit4:junit4] 2> 75491 T254 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 75557 T254 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 75561 T254 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 75566 T254 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 76099 T254 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 76103 T254 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 76106 T254 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 76111 T254 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 76159 T254 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 76160 T254 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.ShardSplitTest-jetty4-1371875201084\collection1\, dataDir=.\org.apache.solr.cloud.ShardSplitTest-1371875180547/jetty4\
[junit4:junit4] 2> 76160 T254 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@3264c826
[junit4:junit4] 2> 76161 T254 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 76162 T254 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1371875180547/jetty4\
[junit4:junit4] 2> 76162 T254 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardSplitTest-1371875180547/jetty4\index/
[junit4:junit4] 2> 76162 T254 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ShardSplitTest-1371875180547\jetty4\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 76163 T254 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1371875180547/jetty4\index
[junit4:junit4] 2> 76167 T254 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@271e47aa lockFactory=org.apache.lucene.store.NativeFSLockFactory@18e5cef7),segFN=segments_1,generation=1}
[junit4:junit4] 2> 76168 T254 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 76171 T254 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 76172 T254 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 76173 T254 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 76174 T254 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 76174 T254 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 76175 T254 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 76179 T254 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 76180 T254 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 76180 T254 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 76190 T254 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 76196 T254 oass.SolrIndexSearcher.<init> Opening Searcher@16d65b1c main
[junit4:junit4] 2> 76197 T254 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.ShardSplitTest-1371875180547\jetty4\tlog
[junit4:junit4] 2> 76198 T254 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 76198 T254 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 76206 T257 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@16d65b1c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 76209 T254 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 76210 T254 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:56644 collection:collection1 shard:shard2
[junit4:junit4] 2> 76225 T254 oasc.ZkController.register We are http://127.0.0.1:56644/collection1/ and leader is http://127.0.0.1:56625/collection1/
[junit4:junit4] 2> 76225 T254 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:56644
[junit4:junit4] 2> 76225 T254 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 76226 T254 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C35 name=collection1 org.apache.solr.core.SolrCore@cd72d2e url=http://127.0.0.1:56644/collection1 node=127.0.0.1:56644_ C35_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:56644_, base_url=http://127.0.0.1:56644}
[junit4:junit4] 2> 76227 T258 C35 P56644 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 76228 T258 C35 P56644 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 76229 T258 C35 P56644 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 76229 T258 C35 P56644 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 76228 T254 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 76232 T258 C35 P56644 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 76235 T162 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 76235 T162 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 76235 T162 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 76242 T162 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 76246 T214 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:56644__collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 76246 T162 oasc.AbstractFullDistribZkTestBase.waitForThingsToLevelOut Wait for recoveries to finish - wait 15 for each attempt
[junit4:junit4] 2> 76247 T162 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):15
[junit4:junit4] 2> 76249 T162 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 76391 T185 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 76395 T185 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:56634__collection1",
[junit4:junit4] 2> "numShards":"2",
[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:56634_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:56634"}
[junit4:junit4] 2> 76417 T185 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:56644__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:56644_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:56644"}
[junit4:junit4] 2> 76438 T253 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 76440 T220 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 76440 T184 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 76440 T204 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 76440 T236 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 76440 T191 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 77246 T214 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:56644__collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 77248 T214 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:56644__collection1&state=recovering&nodeName=127.0.0.1:56644_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1002
[junit4:junit4] 2> 77253 T162 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 78257 T162 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> C35_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:56644_, base_url=http://127.0.0.1:56644}
[junit4:junit4] 2> 79250 T258 C35 P56644 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:56625/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 79250 T258 C35 P56644 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:56644 START replicas=[http://127.0.0.1:56625/collection1/] nUpdates=100
[junit4:junit4] 2> 79252 T258 C35 P56644 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 79252 T258 C35 P56644 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 79252 T258 C35 P56644 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 79252 T258 C35 P56644 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 79253 T258 C35 P56644 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 79256 T258 C35 P56644 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:56625/collection1/. core=collection1
[junit4:junit4] 2> 79257 T258 C35 P56644 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C36 name=collection1 org.apache.solr.core.SolrCore@5d15c3a6 url=http://127.0.0.1:56625/collection1 node=127.0.0.1:56625_ C36_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:56625_, base_url=http://127.0.0.1:56625, leader=true}
[junit4:junit4] 2> 79273 T216 C36 P56625 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 2> 79273 T162 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 79275 T214 C36 P56625 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 79279 T214 C36 P56625 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@156b2796 lockFactory=org.apache.lucene.store.NativeFSLockFactory@42d66ff5),segFN=segments_1,generation=1}
[junit4:junit4] 2> 79280 T214 C36 P56625 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 79280 T214 C36 P56625 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@156b2796 lockFactory=org.apache.lucene.store.NativeFSLockFactory@42d66ff5),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@156b2796 lockFactory=org.apache.lucene.store.NativeFSLockFactory@42d66ff5),segFN=segments_2,generation=2}
[junit4:junit4] 2> 79281 T214 C36 P56625 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 79281 T214 C36 P56625 oass.SolrIndexSearcher.<init> Opening Searcher@491e2104 realtime
[junit4:junit4] 2> 79281 T214 C36 P56625 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 79282 T214 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 8
[junit4:junit4] 2> 79283 T258 C35 P56644 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 79283 T258 C35 P56644 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 79287 T212 C36 P56625 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 79287 T212 C36 P56625 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> 79289 T258 C35 P56644 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 79289 T258 C35 P56644 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 79289 T258 C35 P56644 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 79293 T213 C36 P56625 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=1
[junit4:junit4] 2> 79293 T258 C35 P56644 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 79294 T258 C35 P56644 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1371875180547/jetty4\index.20130622072648627
[junit4:junit4] 2> 79295 T258 C35 P56644 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@6462f6ea lockFactory=org.apache.lucene.store.NativeFSLockFactory@22e8ca96) fullCopy=false
[junit4:junit4] 2> 79297 T215 C36 P56625 oasc.SolrCore.execute [collection1] webapp= path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 79299 T258 C35 P56644 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 79300 T258 C35 P56644 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 79300 T258 C35 P56644 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 79302 T258 C35 P56644 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@271e47aa lockFactory=org.apache.lucene.store.NativeFSLockFactory@18e5cef7),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@271e47aa lockFactory=org.apache.lucene.store.NativeFSLockFactory@18e5cef7),segFN=segments_2,generation=2}
[junit4:junit4] 2> 79303 T258 C35 P56644 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 79303 T258 C35 P56644 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 79303 T258 C35 P56644 oass.SolrIndexSearcher.<init> Opening Searcher@5a61a567 main
[junit4:junit4] 2> 79304 T257 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5a61a567 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 79305 T258 C35 P56644 oasc.CachingDirectoryFactory.closeCacheValue looking to close .\org.apache.solr.cloud.ShardSplitTest-1371875180547/jetty4\index.20130622072648627 [CachedDir<<refCount=0;path=.\org.apache.solr.cloud.ShardSplitTest-1371875180547/jetty4\index.20130622072648627;done=true>>]
[junit4:junit4] 2> 79305 T258 C35 P56644 oasc.CachingDirectoryFactory.close Closing directory: .\org.apache.solr.cloud.ShardSplitTest-1371875180547/jetty4\index.20130622072648627
[junit4:junit4] 2> 79305 T258 C35 P56644 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: .\org.apache.solr.cloud.ShardSplitTest-1371875180547/jetty4\index.20130622072648627
[junit4:junit4] 2> 79306 T258 C35 P56644 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 79307 T258 C35 P56644 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 79307 T258 C35 P56644 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 79307 T258 C35 P56644 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 79316 T258 C35 P56644 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 79477 T185 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 79481 T185 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:56644__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:56644_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:56644"}
[junit4:junit4] 2> 79507 T191 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 79509 T253 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 79510 T204 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 79510 T236 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 79512 T184 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 79513 T220 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 80279 T162 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 80283 T162 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: collection1
[junit4:junit4] 2> ASYNC NEW_CORE C37 name=collection1 org.apache.solr.core.SolrCore@f6a121e url=http://127.0.0.1:56604/collection1 node=127.0.0.1:56604_ C37_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:56604_, base_url=http://127.0.0.1:56604, leader=true}
[junit4:junit4] 2> 80305 T176 C37 P56604 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 80310 T176 C37 P56604 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@66db9181 lockFactory=org.apache.lucene.store.NativeFSLockFactory@66d04849),segFN=segments_1,generation=1}
[junit4:junit4] 2> 80311 T176 C37 P56604 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 80311 T176 C37 P56604 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@66db9181 lockFactory=org.apache.lucene.store.NativeFSLockFactory@66d04849),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@66db9181 lockFactory=org.apache.lucene.store.NativeFSLockFactory@66d04849),segFN=segments_2,generation=2}
[junit4:junit4] 2> 80312 T176 C37 P56604 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 80312 T176 C37 P56604 oass.SolrIndexSearcher.<init> Opening Searcher@23f90490 main
[junit4:junit4] 2> 80313 T176 C37 P56604 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 80313 T188 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@23f90490 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 80316 T176 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 12
[junit4:junit4] 2> 80333 T214 C36 P56625 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:56616/collection1/, StdNode: http://127.0.0.1:56634/collection1/, StdNode: http://127.0.0.1:56625/collection1/, StdNode: http://127.0.0.1:56644/collection1/] params:commit_end_point=true&commit=true&softCommit=false&waitSearcher=true&expungeDeletes=false
[junit4:junit4] 2> ASYNC NEW_CORE C38 name=collection1 org.apache.solr.core.SolrCore@663afdd8 url=http://127.0.0.1:56616/collection1 node=127.0.0.1:56616_ C38_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:56616_, base_url=http://127.0.0.1:56616, leader=true}
[junit4:junit4] 2> 80348 T197 C38 P56616 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> C35_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:56644_, base_url=http://127.0.0.1:56644}
[junit4:junit4] 2> 80359 T244 C35 P56644 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 80362 T212 C36 P56625 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 80363 T197 C38 P56616 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@49b328a lockFactory=org.apache.lucene.store.NativeFSLockFactory@11a390fc),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@49b328a lockFactory=org.apache.lucene.store.NativeFSLockFactory@11a390fc),segFN=segments_3,generation=3}
[junit4:junit4] 2> 80363 T197 C38 P56616 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 80364 T197 C38 P56616 oass.SolrIndexSearcher.<init> Opening Searcher@5bdf8d13 main
[junit4:junit4] 2> 80364 T197 C38 P56616 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 80365 T206 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5bdf8d13 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 80366 T244 C35 P56644 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@271e47aa lockFactory=org.apache.lucene.store.NativeFSLockFactory@18e5cef7),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@271e47aa lockFactory=org.apache.lucene.store.NativeFSLockFactory@18e5cef7),segFN=segments_3,generation=3}
[junit4:junit4] 2> 80367 T244 C35 P56644 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 80368 T197 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 20
[junit4:junit4] 2> 80369 T244 C35 P56644 oass.SolrIndexSearcher.<init> Opening Searcher@6d60098d main
[junit4:junit4] 2> 80370 T212 C36 P56625 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@156b2796 lockFactory=org.apache.lucene.store.NativeFSLockFactory@42d66ff5),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@156b2796 lockFactory=org.apache.lucene.store.NativeFSLockFactory@42d66ff5),segFN=segments_3,generation=3}
[junit4:junit4] 2> 80370 T212 C36 P56625 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 80370 T212 C36 P56625 oass.SolrIndexSearcher.<init> Opening Searcher@13d3ffdc main
[junit4:junit4] 2> 80370 T244 C35 P56644 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> ASYNC NEW_CORE C39 name=collection1 org.apache.solr.core.SolrCore@64bbe1ee url=http://127.0.0.1:56634/collection1 node=127.0.0.1:56634_ C39_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:56634_, base_url=http://127.0.0.1:56634}
[junit4:junit4] 2> 80369 T229 C39 P56634 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 80371 T212 C36 P56625 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 80370 T257 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6d60098d main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 80373 T229 C39 P56634 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@383bd328 lockFactory=org.apache.lucene.store.NativeFSLockFactory@78aa6cbd),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@383bd328 lockFactory=org.apache.lucene.store.NativeFSLockFactory@78aa6cbd),segFN=segments_3,generation=3}
[junit4:junit4] 2> 80374 T229 C39 P56634 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 80373 T222 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@13d3ffdc main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 80373 T244 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 14
[junit4:junit4] 2> 80375 T212 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 13
[junit4:junit4] 2> 80374 T229 C39 P56634 oass.SolrIndexSearcher.<init> Opening Searcher@74b2b9c3 main
[junit4:junit4] 2> 80376 T229 C39 P56634 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 80377 T238 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@74b2b9c3 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 80378 T229 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 9
[junit4:junit4] 2> 80378 T214 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 45
[junit4:junit4] 2> 80380 T162 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 80385 T199 C38 P56616 oasc.SolrCore.execute [collection1] webapp= path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=1
[junit4:junit4] 2> 80388 T230 C39 P56634 oasc.SolrCore.execute [collection1] webapp= path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=1
[junit4:junit4] 2> 80390 T213 C36 P56625 oasc.SolrCore.execute [collection1] webapp= path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4] 2> 80394 T246 C35 P56644 oasc.SolrCore.execute [collection1] webapp= path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4] 2> 82412 T180 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1438515422025482240)} 0 13
[junit4:junit4] 2> 82436 T246 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={update.distrib=FROMLEADER&_version_=-1438515422049599488&update.from=http://127.0.0.1:56625/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1438515422049599488)} 0 1
[junit4:junit4] 2> 82436 T229 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={update.distrib=FROMLEADER&_version_=-1438515422049599488&update.from=http://127.0.0.1:56616/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1438515422049599488)} 0 1
[junit4:junit4] 2> 82437 T212 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={update.distrib=TOLEADER&wt=javabin&version=2} {deleteByQuery=*:* (-1438515422049599488)} 0 8
[junit4:junit4] 2> 82438 T197 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={update.distrib=TOLEADER&wt=javabin&version=2} {deleteByQuery=*:* (-1438515422049599488)} 0 9
[junit4:junit4] 2> 82439 T244 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {deleteByQuery=*:*} 0 20
[junit4:junit4] 2> 82446 T176 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[a!0 (1438515422063230976)]} 0 3
[junit4:junit4] 2> 82468 T247 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56625/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[a!0 (1438515422083153920)]} 0 2
[junit4:junit4] 2> 82468 T213 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[a!0 (1438515422083153920)]} 0 7
[junit4:junit4] 2> 82470 T199 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[a!0]} 0 22
[junit4:junit4] 2> 82475 T177 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[b!1 (1438515422095736832)]} 0 2
[junit4:junit4] 2> 82488 T230 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[b!1 (1438515422104125440)]} 0 3
[junit4:junit4] 2> 82489 T200 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56644/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[b!1 (1438515422104125440)]} 0 8
[junit4:junit4] 2> 82492 T248 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[b!1]} 0 14
[junit4:junit4] 2> 82497 T178 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[c!2 (1438515422118805504)]} 0 1
[junit4:junit4] 2> 82514 T231 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[c!2 (1438515422130339840)]} 0 4
[junit4:junit4] 2> 82516 T198 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56644/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[c!2 (1438515422130339840)]} 0 10
[junit4:junit4] 2> 82519 T249 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[c!2]} 0 17
[junit4:junit4] 2> 82525 T179 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[d!3 (1438515422148165632)]} 0 2
[junit4:junit4] 2> 82534 T245 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56625/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[d!3 (1438515422154457088)]} 0 1
[junit4:junit4] 2> 82535 T215 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[d!3 (1438515422154457088)]} 0 5
[junit4:junit4] 2> 82536 T196 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[d!3]} 0 9
[junit4:junit4] 2> 82540 T175 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[e!4 (1438515422164942848)]} 0 1
[junit4:junit4] 2> 82551 T246 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56625/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[e!4 (1438515422172282880)]} 0 1
[junit4:junit4] 2> 82552 T216 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[e!4 (1438515422172282880)]} 0 6
[junit4:junit4] 2> 82553 T195 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[e!4]} 0 10
[junit4:junit4] 2> 82556 T180 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[f!5 (1438515422180671488)]} 0 1
[junit4:junit4] 2> 82570 T247 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56625/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[f!5 (1438515422189060096)]} 0 2
[junit4:junit4] 2> 82571 T211 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56644/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[f!5 (1438515422189060096)]} 0 8
[junit4:junit4] 2> 82573 T244 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[f!5]} 0 14
[junit4:junit4] 2> 82580 T176 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[g!6 (1438515422204788736)]} 0 1
[junit4:junit4] 2> 82602 T232 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[g!6 (1438515422222614528)]} 0 2
[junit4:junit4] 2> 82604 T197 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56644/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[g!6 (1438515422222614528)]} 0 10
[junit4:junit4] 2> 82607 T248 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[g!6]} 0 23
[junit4:junit4] 2> 82613 T177 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[h!7 (1438515422240440320)]} 0 1
[junit4:junit4] 2> 82628 T227 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[h!7 (1438515422251974656)]} 0 1
[junit4:junit4] 2> 82629 T199 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56644/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[h!7 (1438515422251974656)]} 0 6
[junit4:junit4] 2> 82630 T249 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[h!7]} 0 11
[junit4:junit4] 2> 82634 T178 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[i!8 (1438515422263508992)]} 0 0
[junit4:junit4] 2> 82645 T229 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[i!8 (1438515422270849024)]} 0 1
[junit4:junit4] 2> 82646 T200 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56634/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[i!8 (1438515422270849024)]} 0 5
[junit4:junit4] 2> 82647 T228 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[i!8]} 0 11
[junit4:junit4] 2> 82650 T179 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[j!9 (1438515422280286208)]} 0 0
[junit4:junit4] 2> 82661 T230 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[j!9 (1438515422287626240)]} 0 1
[junit4:junit4] 2> 82663 T198 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56644/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[j!9 (1438515422287626240)]} 0 6
[junit4:junit4] 2> 82664 T245 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[j!9]} 0 10
[junit4:junit4] 2> 82667 T175 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[k!10 (1438515422298112000)]} 0 0
[junit4:junit4] 2> 82679 T231 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[k!10 (1438515422307549184)]} 0 1
[junit4:junit4] 2> 82681 T196 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56644/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[k!10 (1438515422307549184)]} 0 5
[junit4:junit4] 2> 82682 T246 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[k!10]} 0 8
[junit4:junit4] 2> 82685 T180 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[l!11 (1438515422315937792)]} 0 1
[junit4:junit4] 2> 82692 T247 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56625/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[l!11 (1438515422320132096)]} 0 1
[junit4:junit4] 2> 82693 T214 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[l!11 (1438515422320132096)]} 0 5
[junit4:junit4] 2> 82697 T176 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[m!12 (1438515422329569280)]} 0 1
[junit4:junit4] 2> 82709 T244 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56625/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[m!12 (1438515422335860736)]} 0 0
[junit4:junit4] 2> 82711 T212 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[m!12 (1438515422335860736)]} 0 8
[junit4:junit4] 2> 82712 T195 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[m!12]} 0 12
[junit4:junit4] 2> 82716 T177 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[n!13 (1438515422348443648)]} 0 1
[junit4:junit4] 2> 82724 T232 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[n!13 (1438515422353686528)]} 0 1
[junit4:junit4] 2> 82726 T197 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56625/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[n!13 (1438515422353686528)]} 0 6
[junit4:junit4] 2> 82727 T213 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[n!13]} 0 9
[junit4:junit4] 2> 82730 T178 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[o!14 (1438515422364172288)]} 0 0
[junit4:junit4] 2> 82741 T249 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56625/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[o!14 (1438515422371512320)]} 0 0
[junit4:junit4] 2> 82743 T215 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56644/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[o!14 (1438515422371512320)]} 0 6
[junit4:junit4] 2> 82744 T248 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[o!14]} 0 10
[junit4:junit4] 2> 82748 T179 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[p!15 (1438515422381998080)]} 0 1
[junit4:junit4] 2> 82754 T227 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[p!15 (1438515422385143808)]} 0 1
[junit4:junit4] 2> 82755 T199 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[p!15 (1438515422385143808)]} 0 5
[junit4:junit4] 2> 82758 T175 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[q!16 (1438515422393532416)]} 0 0
[junit4:junit4] 2> 82768 T229 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[q!16 (1438515422400872448)]} 0 1
[junit4:junit4] 2> 82769 T200 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56625/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[q!16 (1438515422400872448)]} 0 5
[junit4:junit4] 2> 82770 T216 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[q!16]} 0 9
[junit4:junit4] 2> 82773 T180 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[r!17 (1438515422408212480)]} 0 1
[junit4:junit4] 2> 82780 T245 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56625/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[r!17 (1438515422412406784)]} 0 1
[junit4:junit4] 2> 82782 T211 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[r!17 (1438515422412406784)]} 0 6
[junit4:junit4] 2> 82785 T176 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[s!18 (1438515422420795392)]} 0 1
[junit4:junit4] 2> 82795 T230 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[s!18 (1438515422428135424)]} 0 1
[junit4:junit4] 2> 82796 T198 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56634/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[s!18 (1438515422428135424)]} 0 5
[junit4:junit4] 2> 82797 T228 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[s!18]} 0 9
[junit4:junit4] 2> 82801 T177 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[t!19 (1438515422438621184)]} 0 1
[junit4:junit4] 2> 82811 T232 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[t!19 (1438515422443864064)]} 0 2
[junit4:junit4] 2> 82812 T196 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56634/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[t!19 (1438515422443864064)]} 0 6
[junit4:junit4] 2> 82813 T231 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[t!19]} 0 10
[junit4:junit4] 2> 82818 T179 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[u!20 (1438515422456446976)]} 0 0
[junit4:junit4] 2> 82832 T246 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56625/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[u!20 (1438515422464835584)]} 0 1
[junit4:junit4] 2> 82834 T214 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[u!20 (1438515422464835584)]} 0 9
[junit4:junit4] 2> 82835 T197 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[u!20]} 0 13
[junit4:junit4] 2> 82840 T175 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[v!21 (1438515422478467072)]} 0 1
[junit4:junit4] 2> 82855 T229 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[v!21 (1438515422490001408)]} 0 1
[junit4:junit4] 2> 82858 T199 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56644/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[v!21 (1438515422490001408)]} 0 9
[junit4:junit4] 2> 82859 T244 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[v!21]} 0 14
[junit4:junit4] 2> 82866 T180 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[w!22 (1438515422504681472)]} 0 2
[junit4:junit4] 2> 82876 T230 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[w!22 (1438515422512021504)]} 0 1
[junit4:junit4] 2> 82878 T200 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[w!22 (1438515422512021504)]} 0 8
[junit4:junit4] 2> 82884 T176 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[x!23 (1438515422524604416)]} 0 1
[junit4:junit4] 2> 82900 T249 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56625/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[x!23 (1438515422535090176)]} 0 2
[junit4:junit4] 2> 82901 T213 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[x!23 (1438515422535090176)]} 0 8
[junit4:junit4] 2> 82903 T198 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[x!23]} 0 14
[junit4:junit4] 2> 82909 T177 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[y!24 (1438515422550818816)]} 0 1
[junit4:junit4] 2> 82926 T245 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56625/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[y!24 (1438515422562353152)]} 0 2
[junit4:junit4] 2> 82926 T215 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56644/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[y!24 (1438515422562353152)]} 0 7
[junit4:junit4] 2> 82929 T248 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[y!24]} 0 15
[junit4:junit4] 2> 82935 T178 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[z!25 (1438515422578081792)]} 0 1
[junit4:junit4] 2> 82952 T228 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[z!25 (1438515422590664704)]} 0 2
[junit4:junit4] 2> 82954 T196 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56625/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[z!25 (1438515422590664704)]} 0 9
[junit4:junit4] 2> 82955 T216 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[z!25]} 0 14
[junit4:junit4] 2> 82961 T179 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[a!26 (1438515422605344768)]} 0 1
[junit4:junit4] 2> 82978 T246 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56625/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[a!26 (1438515422615830528)]} 0 2
[junit4:junit4] 2> 82979 T211 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56644/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[a!26 (1438515422615830528)]} 0 9
[junit4:junit4] 2> 82981 T247 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[a!26]} 0 14
[junit4:junit4] 2> 82987 T175 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[b!27 (1438515422632607744)]} 0 1
[junit4:junit4] 2> 83003 T227 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[b!27 (1438515422644142080)]} 0 2
[junit4:junit4] 2> 83007 T195 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56625/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[b!27 (1438515422644142080)]} 0 11
[junit4:junit4] 2> 83009 T212 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[b!27]} 0 17
[junit4:junit4] 2> 83012 T180 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[c!28 (1438515422658822144)]} 0 1
[junit4:junit4] 2> 83025 T232 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[c!28 (1438515422667210752)]} 0 1
[junit4:junit4] 2> 83025 T197 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56644/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[c!28 (1438515422667210752)]} 0 6
[junit4:junit4] 2> 83026 T244 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[c!28]} 0 11
[junit4:junit4] 2> 83030 T176 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[d!29 (1438515422678745088)]} 0 1
[junit4:junit4] 2> 83040 T249 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56625/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[d!29 (1438515422683987968)]} 0 1
[junit4:junit4] 2> 83041 T214 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56634/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[d!29 (1438515422683987968)]} 0 6
[junit4:junit4] 2> 83043 T231 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[d!29]} 0 11
[junit4:junit4] 2> 83046 T177 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[e!30 (1438515422695522304)]} 0 0
[junit4:junit4] 2> 83057 T248 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56625/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[e!30 (1438515422702862336)]} 0 0
[junit4:junit4] 2> 83058 T213 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56644/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[e!30 (1438515422702862336)]} 0 5
[junit4:junit4] 2> 83068 T245 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[e!30]} 0 19
[junit4:junit4] 2> 83073 T178 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[f!31 (1438515422722785280)]} 0 1
[junit4:junit4] 2> 83086 T246 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56625/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[f!31 (1438515422733271040)]} 0 1
[junit4:junit4] 2> 83087 T215 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[f!31 (1438515422733271040)]} 0 5
[junit4:junit4] 2> 83089 T199 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[f!31]} 0 13
[junit4:junit4] 2> 83093 T179 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[g!32 (1438515422743756800)]} 0 1
[junit4:junit4] 2> 83102 T229 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[g!32 (1438515422750048256)]} 0 0
[junit4:junit4] 2> 83104 T200 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56644/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[g!32 (1438515422750048256)]} 0 6
[junit4:junit4] 2> 83105 T247 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[g!32]} 0 10
[junit4:junit4] 2> 83109 T175 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[h!33 (1438515422761582592)]} 0 1
[junit4:junit4] 2> 83146 T228 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[h!33 (1438515422772068352)]} 0 0
[junit4:junit4] 2> 83149 T198 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56634/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[h!33 (1438515422772068352)]} 0 30
[junit4:junit4] 2> 83150 T230 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[h!33]} 0 36
[junit4:junit4] 2> 83153 T180 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[i!34 (1438515422806671360)]} 0 1
[junit4:junit4] 2> 83168 T227 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[i!34 (1438515422819254272)]} 0 1
[junit4:junit4] 2> 83170 T196 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56625/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[i!34 (1438515422819254272)]} 0 12
[junit4:junit4] 2> 83171 T216 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[i!34]} 0 16
[junit4:junit4] 2> 83174 T176 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[j!35 (1438515422828691456)]} 0 1
[junit4:junit4] 2> 83183 T232 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[j!35 (1438515422834982912)]} 0 0
[junit4:junit4] 2> 83185 T195 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56644/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[j!35 (1438515422834982912)]} 0 6
[junit4:junit4] 2> 83186 T244 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[j!35]} 0 10
[junit4:junit4] 2> 83190 T177 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[k!36 (1438515422846517248)]} 0 1
[junit4:junit4] 2> 83202 T229 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[k!36 (1438515422854905856)]} 0 1
[junit4:junit4] 2> 83203 T197 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56634/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[k!36 (1438515422854905856)]} 0 5
[junit4:junit4] 2> 83204 T231 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[k!36]} 0 11
[junit4:junit4] 2> 83210 T178 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[l!37 (1438515422865391616)]} 0 2
[junit4:junit4] 2> 83223 T249 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56625/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[l!37 (1438515422875877376)]} 0 1
[junit4:junit4] 2> 83225 T211 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56634/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[l!37 (1438515422875877376)]} 0 7
[junit4:junit4] 2> 83226 T228 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[l!37]} 0 12
[junit4:junit4] 2> 83231 T175 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[m!38 (1438515422888460288)]} 0 1
[junit4:junit4] 2> 83242 T248 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56625/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[m!38 (1438515422896848896)]} 0 1
[junit4:junit4] 2> 83242 T212 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56634/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[m!38 (1438515422896848896)]} 0 4
[junit4:junit4] 2> 83243 T227 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[m!38]} 0 8
[junit4:junit4] 2> 83248 T180 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[n!39 (1438515422907334656)]} 0 2
[junit4:junit4] 2> 83260 T232 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[n!39 (1438515422915723264)]} 0 1
[junit4:junit4] 2> 83262 T199 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56644/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[n!39 (1438515422915723264)]} 0 7
[junit4:junit4] 2> 83263 T246 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[n!39]} 0 10
[junit4:junit4] 2> 83267 T176 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[o!40 (1438515422926209024)]} 0 1
[junit4:junit4] 2> 83277 T247 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56625/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[o!40 (1438515422934597632)]} 0 0
[junit4:junit4] 2> 83278 T213 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[o!40 (1438515422934597632)]} 0 5
[junit4:junit4] 2> 83279 T198 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[o!40]} 0 9
[junit4:junit4] 2> 83282 T177 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[p!41 (1438515422942986240)]} 0 0
[junit4:junit4] 2> 83295 T229 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[p!41 (1438515422952423424)]} 0 0
[junit4:junit4] 2> 83300 T196 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56644/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[p!41 (1438515422952423424)]} 0 9
[junit4:junit4] 2> 83301 T244 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[p!41]} 0 14
[junit4:junit4] 2> 83307 T179 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[q!42 (1438515422968152064)]} 0 2
[junit4:junit4] 2> 83317 T231 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[q!42 (1438515422973394944)]} 0 1
[junit4:junit4] 2> 83319 T195 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[q!42 (1438515422973394944)]} 0 9
[junit4:junit4] 2> 83325 T178 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[r!43 (1438515422988075008)]} 0 0
[junit4:junit4] 2> 83339 T249 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56625/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[r!43 (1438515422997512192)]} 0 1
[junit4:junit4] 2> 83342 T215 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[r!43 (1438515422997512192)]} 0 8
[junit4:junit4] 2> 83346 T175 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[s!44 (1438515423009046528)]} 0 1
[junit4:junit4] 2> 83355 T230 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[s!44 (1438515423017435136)]} 0 0
[junit4:junit4] 2> 83357 T197 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56625/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[s!44 (1438515423017435136)]} 0 5
[junit4:junit4] 2> 83358 T216 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[s!44]} 0 9
[junit4:junit4] 2> 83361 T180 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[t!45 (1438515423024775168)]} 0 1
[junit4:junit4] 2> 83372 T227 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56616/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[t!45 (1438515423032115200)]} 0 2
[junit4:junit4] 2> 83373 T200 C38 P56616 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56634/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[t!45 (1438515423032115200)]} 0 6
[junit4:junit4] 2> 83374 T228 C39 P56634 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[t!45]} 0 10
[junit4:junit4] 2> 83378 T176 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[u!46 (1438515423043649536)]} 0 0
[junit4:junit4] 2> 83386 T245 C35 P56644 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:56625/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[u!46 (1438515423048892416)]} 0 1
[junit4:junit4] 2> 83387 T211 C36 P56625 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[u!46 (1438515423048892416)]} 0 4
[junit4:junit4] 2> 83391 T177 C37 P56604 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[v!47 (1438515423057281024)]} 0 1
[junit4:junit4] 2> 83402 T232 C39 P56634 oasup.LogUpdateProcess
[...truncated too long message...]
est-1371876482734\jetty4 [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.SyncSliceTest-1371876482734\jetty4;done=false>>]
[junit4:junit4] 2> 1495983 T3966 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.SyncSliceTest-1371876482734\jetty4
[junit4:junit4] 2> 1495983 T3966 oasc.CachingDirectoryFactory.closeCacheValue looking to close C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.SyncSliceTest-1371876482734\jetty4\index.20130622014906443 [CachedDir<<refCount=0;path=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.SyncSliceTest-1371876482734\jetty4\index.20130622014906443;done=false>>]
[junit4:junit4] 2> 1495983 T3966 oasc.CachingDirectoryFactory.close Closing directory: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\org.apache.solr.cloud.SyncSliceTest-1371876482734\jetty4\index.20130622014906443
[junit4:junit4] 2> 1495984 T3966 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 1495985 T3966 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /collections/collection1/leader_elect/shard1/election/89907297173110796-127.0.0.1:58771_kk_ru%2Fob_collection1-n_0000000003
[junit4:junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4:junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4:junit4] 2> at org.apache.zookeeper.ZooKeeper.delete(ZooKeeper.java:873)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:152)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$2.execute(SolrZkClient.java:149)
[junit4:junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.delete(SolrZkClient.java:149)
[junit4:junit4] 2> at org.apache.solr.cloud.ElectionContext.cancelElection(ElectionContext.java:63)
[junit4:junit4] 2> at org.apache.solr.cloud.ShardLeaderElectionContext.runLeaderProcess(ElectionContext.java:260)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.runIamLeaderProcess(LeaderElector.java:156)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:100)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4:junit4] 2>
[junit4:junit4] 2> 1495985 T3966 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
[junit4:junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4:junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4:junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:235)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:232)
[junit4:junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:232)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:84)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4:junit4] 2>
[junit4:junit4] 2> 1495986 T3966 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 1495986 T3966 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> 1495987 T3966 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {range_facet_l=PostingsFormat(name=Lucene41WithOrds), text=Lucene41(blocksize=128), _version_=PostingsFormat(name=MockRandom), rnd_b=PostingsFormat(name=Direct), intDefault=PostingsFormat(name=MockRandom), timestamp=PostingsFormat(name=Lucene41WithOrds), id=PostingsFormat(name=Direct), a_t=PostingsFormat(name=Lucene41WithOrds), range_facet_sl=PostingsFormat(name=Direct), range_facet_si=PostingsFormat(name=Lucene41WithOrds), other_tl1=PostingsFormat(name=MockRandom), multiDefault=PostingsFormat(name=Lucene41WithOrds), a_si=PostingsFormat(name=MockRandom)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=lt, timezone=America/Maceio
[junit4:junit4] 2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=2,threads=3,free=177800072,total=358678528
[junit4:junit4] 2> NOTE: All tests run in this JVM: [OutputWriterTest, TestSolrQueryParserResource, TestReload, XmlUpdateRequestHandlerTest, TestExtendedDismaxParser, TestCSVLoader, LegacyHTMLStripCharFilterTest, TestSuggestSpellingConverter, TestUniqueKeyFieldResource, PeerSyncTest, TestWriterPerf, TestSolrCoreProperties, ShardSplitTest, TestLazyCores, TestBinaryResponseWriter, StatelessScriptUpdateProcessorFactoryTest, TestSolr4Spatial, JSONWriterTest, TestCodecSupport, TestFieldResource, BasicDistributedZkTest, NoCacheHeaderTest, SolrCoreTest, IndexBasedSpellCheckerTest, TestFieldTypeResource, TestSweetSpotSimilarityFactory, CSVRequestHandlerTest, BadComponentTest, TestCloudManagedSchema, TestFieldCollectionResource, HardAutoCommitTest, AlternateDirectoryTest, SpatialFilterTest, TestSchemaVersionResource, LeaderElectionIntegrationTest, PolyFieldTest, TestMultiCoreConfBootstrap, PingRequestHandlerTest, TestComponentsName, ShardRoutingTest, SystemInfoHandlerTest, QueryParsingTest, StatsComponentTest, OverseerCollectionProcessorTest, SolrCmdDistributorTest, CachingDirectoryFactoryTest, CircularListTest, LoggingHandlerTest, TestFoldingMultitermQuery, TestSolrXml, TestPostingsSolrHighlighter, ZkSolrClientTest, TestConfig, TestAnalyzedSuggestions, TestStressReorder, TestRecovery, CollectionsAPIDistributedZkTest, DirectSolrConnectionTest, SuggesterTSTTest, ChaosMonkeySafeLeaderTest, TestReloadAndDeleteDocs, ResourceLoaderTest, TestIndexingPerformance, AnalysisAfterCoreReloadTest, IndexReaderFactoryTest, TestPropInject, NumericFieldsTest, TestRandomFaceting, TestSolrIndexConfig, TestBinaryField, TestRealTimeGet, WordBreakSolrSpellCheckerTest, SuggesterWFSTTest, TestCollationField, ZkCLITest, TestFastWriter, AliasIntegrationTest, StandardRequestHandlerTest, CacheHeaderTest, DirectUpdateHandlerOptimizeTest, TestSystemIdResolver, TestRTGBase, TestHashPartitioner, UpdateRequestProcessorFactoryTest, TestCollationKeyRangeQueries, TestCloudManagedSchemaAddField, CoreAdminHandlerTest, TestSolrXmlPersistence, SolrTestCaseJ4Test, ScriptEngineTest, TestDynamicFieldResource, CoreContainerCoreInitFailuresTest, TestDocumentBuilder, TestJmxIntegration, TestFaceting, SpellingQueryConverterTest, TestDefaultSimilarityFactory, TermVectorComponentTest, UnloadDistributedZkTest, ShowFileRequestHandlerTest, TestRemoteStreaming, TestSchemaResource, TestRandomDVFaceting, SignatureUpdateProcessorFactoryTest, ChaosMonkeyNothingIsSafeTest, TestWordDelimiterFilterFactory, RequiredFieldsTest, SpellPossibilityIteratorTest, DocValuesTest, TestBM25SimilarityFactory, DebugComponentTest, SolrRequestParserTest, FileBasedSpellCheckerTest, FastVectorHighlighterTest, TestValueSourceCache, FullSolrCloudDistribCmdsTest, DistributedQueryElevationComponentTest, SyncSliceTest]
[junit4:junit4] Completed in 143.61s, 1 test, 1 failure <<< FAILURES!
[...truncated 561 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:392: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:372: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build.xml:181: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\common-build.xml:437: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1246: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:890: There were test failures: 298 suites, 1255 tests, 1 error, 2 failures, 18 ignored (12 assumptions)
Total time: 65 minutes 56 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_25 -XX:+UseCompressedOops -XX:+UseParallelGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure