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/05/27 14:25:11 UTC
[JENKINS] Lucene-Solr-trunk-Windows (64bit/jdk1.7.0_21) - Build #
2867 - Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/2867/
Java: 64bit/jdk1.7.0_21 -XX:+UseCompressedOops -XX:+UseSerialGC
2 tests failed.
REGRESSION: org.apache.solr.cloud.ShardSplitTest.testDistribSearch
Error Message:
Wrong doc count on shard1_0 expected:<94> but was:<93>
Stack Trace:
java.lang.AssertionError: Wrong doc count on shard1_0 expected:<94> but was:<93>
at __randomizedtesting.SeedInfo.seed([B9E7227F21A1A772:3801AC6756FEC74E]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.apache.solr.cloud.ShardSplitTest.checkDocCountsAndShardStates(ShardSplitTest.java:166)
at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:142)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:601)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:722)
FAILED: org.apache.solr.cloud.ChaosMonkeyShardSplitTest.testDistribSearch
Error Message:
Server at http://127.0.0.1:65304 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:65304 returned non ok status:500, message:Server Error
at __randomizedtesting.SeedInfo.seed([B9E7227F21A1A772:3801AC6756FEC74E]: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:208)
at org.apache.solr.cloud.ChaosMonkeyShardSplitTest.doTest(ChaosMonkeyShardSplitTest.java:136)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:601)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:722)
Build Log:
[...truncated 9110 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.ShardSplitTest
[junit4:junit4] 2> 12656 T14 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4] 2> 12665 T14 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-ShardSplitTest-1369655086688
[junit4:junit4] 2> 12674 T14 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 12681 T15 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 12902 T14 oasc.ZkTestServer.run start zk server on port:63691
[junit4:junit4] 2> 13112 T14 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 13231 T21 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@446adaa2 name:ZooKeeperConnection Watcher:127.0.0.1:63691 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 13232 T14 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 13237 T14 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 13318 T14 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 13320 T16 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13ee5ce0f780000, likely client has closed socket
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2>
[junit4:junit4] 2> 13325 T23 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7ec5ab2 name:ZooKeeperConnection Watcher:127.0.0.1:63691/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 13326 T14 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 13345 T14 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 13355 T14 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 13364 T14 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 13371 T14 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 13379 T14 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 13400 T14 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 13416 T14 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\schema15.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 13417 T14 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 13426 T14 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 13427 T14 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 13434 T14 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 13435 T14 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 13444 T14 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 13446 T14 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 13454 T14 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 13455 T14 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 13466 T14 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 13466 T14 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 13481 T14 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 13483 T14 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 13492 T14 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 13493 T14 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 14426 T14 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 14707 T14 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:63698
[junit4:junit4] 2> 14752 T14 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 14754 T14 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 14755 T14 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1369655087526
[junit4:junit4] 2> 14756 T14 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1369655087526\solr.xml
[junit4:junit4] 2> 14757 T14 oasc.CoreContainer.<init> New CoreContainer 910503779
[junit4:junit4] 2> 14760 T14 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1369655087526\'
[junit4:junit4] 2> 14760 T14 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1369655087526\'
[junit4:junit4] 2> 15116 T14 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 15118 T14 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 15119 T14 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 15120 T14 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 15121 T14 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 15121 T14 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 15122 T14 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 15122 T14 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 15123 T14 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 15167 T14 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 15822 T14 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 15823 T14 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:63691/solr
[junit4:junit4] 2> 15845 T14 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 15849 T14 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 15875 T36 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5166db1b name:ZooKeeperConnection Watcher:127.0.0.1:63691 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 15877 T14 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 15885 T16 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13ee5ce0f780002, likely client has closed socket
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2>
[junit4:junit4] 2> 15889 T14 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 15908 T14 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 15917 T38 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@585cbda6 name:ZooKeeperConnection Watcher:127.0.0.1:63691/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 15929 T14 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 15944 T14 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 15976 T14 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 16005 T14 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 16014 T14 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63698_
[junit4:junit4] 2> 16030 T14 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:63698_
[junit4:junit4] 2> 16044 T14 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 16081 T14 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 16089 T14 oasc.Overseer.start Overseer (id=89761715779534851-127.0.0.1:63698_-n_0000000000) starting
[junit4:junit4] 2> 16119 T14 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 16144 T14 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 16150 T40 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 16159 T14 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 16180 T14 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 16214 T39 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 16264 T41 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1369655087526\collection1
[junit4:junit4] 2> 16265 T41 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 16267 T41 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 16268 T41 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 16277 T41 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1369655087526\collection1\'
[junit4:junit4] 2> 16281 T41 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1369655087526/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 16284 T41 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1369655087526/collection1/lib/README' to classloader
[junit4:junit4] 2> 16435 T41 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 16593 T41 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 16597 T41 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 16643 T41 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 18059 T41 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 18065 T41 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 18076 T41 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 18093 T41 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 18218 T41 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 18219 T41 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-controljetty-1369655087526\collection1\, dataDir=.\org.apache.solr.cloud.ShardSplitTest-1369655086687/control/data\
[junit4:junit4] 2> 18228 T41 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5ebd50b9
[junit4:junit4] 2> 18234 T41 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 18236 T41 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1369655086687/control/data\
[junit4:junit4] 2> 18236 T41 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardSplitTest-1369655086687/control/data\index/
[junit4:junit4] 2> 18236 T41 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ShardSplitTest-1369655086687\control\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 18238 T41 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1369655086687/control/data\index
[junit4:junit4] 2> 18245 T41 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@73b58165 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3e6bb568),segFN=segments_1,generation=1}
[junit4:junit4] 2> 18245 T41 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 18360 T41 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 18361 T41 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 18495 T41 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 18504 T41 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 18532 T41 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 18533 T41 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 18539 T41 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 18559 T41 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 18565 T41 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 18577 T41 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 18585 T41 oass.SolrIndexSearcher.<init> Opening Searcher@ab089a9 main
[junit4:junit4] 2> 18622 T41 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.ShardSplitTest-1369655086687\control\data\tlog
[junit4:junit4] 2> 18644 T41 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 18645 T41 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 18738 T42 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@ab089a9 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 18747 T41 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 18747 T41 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 19690 T39 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 19692 T39 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:63698_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63698"}
[junit4:junit4] 2> 19693 T39 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 19718 T39 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 19753 T38 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> 19909 T41 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 19910 T41 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:63698 collection:control_collection shard:shard1
[junit4:junit4] 2> 19931 T41 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4:junit4] 2> 19951 T41 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 20001 T41 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 20009 T41 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 20010 T41 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 20011 T41 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:63698/collection1/
[junit4:junit4] 2> 20011 T41 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 20012 T41 oasc.SyncStrategy.syncToMe http://127.0.0.1:63698/collection1/ has no replicas
[junit4:junit4] 2> 20012 T41 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:63698/collection1/
[junit4:junit4] 2> 20012 T41 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 21501 T39 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 21564 T38 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> 21617 T41 oasc.ZkController.register We are http://127.0.0.1:63698/collection1/ and leader is http://127.0.0.1:63698/collection1/
[junit4:junit4] 2> 21622 T41 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:63698
[junit4:junit4] 2> 21622 T41 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 21624 T41 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 21624 T41 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 21628 T41 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 21636 T14 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 21637 T14 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 21704 T14 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 21724 T14 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 21730 T14 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 21736 T45 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@45168774 name:ZooKeeperConnection Watcher:127.0.0.1:63691/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 21737 T14 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 21740 T14 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 21749 T14 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 22207 T14 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 22212 T14 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:63710
[junit4:junit4] 2> 22213 T14 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 22215 T14 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 22215 T14 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1369655095773
[junit4:junit4] 2> 22216 T14 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1369655095773\solr.xml
[junit4:junit4] 2> 22216 T14 oasc.CoreContainer.<init> New CoreContainer 629076881
[junit4:junit4] 2> 22217 T14 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1369655095773\'
[junit4:junit4] 2> 22218 T14 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1369655095773\'
[junit4:junit4] 2> 22385 T14 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 22385 T14 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 22387 T14 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 22387 T14 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 22388 T14 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 22388 T14 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 22389 T14 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 22390 T14 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 22391 T14 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 22392 T14 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 22407 T14 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 22408 T14 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:63691/solr
[junit4:junit4] 2> 22408 T14 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 22412 T14 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 22436 T56 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@51d3a2d5 name:ZooKeeperConnection Watcher:127.0.0.1:63691 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 22438 T14 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 22448 T14 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 22458 T14 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 22463 T58 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@51d22b42 name:ZooKeeperConnection Watcher:127.0.0.1:63691/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 22464 T14 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 22476 T14 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 23312 T39 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 23315 T39 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:63698_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63698"}
[junit4:junit4] 2> 23332 T58 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> 23333 T38 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> 23333 T45 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> 23636 T14 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63710_
[junit4:junit4] 2> 23641 T14 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:63710_
[junit4:junit4] 2> 23647 T38 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> 23647 T45 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> 23651 T58 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 23651 T58 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> 23656 T38 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 23657 T45 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 23673 T59 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1369655095773\collection1
[junit4:junit4] 2> 23679 T59 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 23680 T59 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 23680 T59 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 23686 T59 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1369655095773\collection1\'
[junit4:junit4] 2> 23688 T59 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1369655095773/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 23689 T59 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1369655095773/collection1/lib/README' to classloader
[junit4:junit4] 2> 23768 T59 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 23869 T59 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 23872 T59 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 23906 T59 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 24837 T59 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 24845 T59 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 24851 T59 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 24865 T59 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 24992 T59 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 24994 T59 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty1-1369655095773\collection1\, dataDir=.\org.apache.solr.cloud.ShardSplitTest-1369655086687/jetty1\
[junit4:junit4] 2> 24997 T59 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5ebd50b9
[junit4:junit4] 2> 25006 T59 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 25007 T59 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1369655086687/jetty1\
[junit4:junit4] 2> 25008 T59 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardSplitTest-1369655086687/jetty1\index/
[junit4:junit4] 2> 25009 T59 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ShardSplitTest-1369655086687\jetty1\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 25010 T59 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1369655086687/jetty1\index
[junit4:junit4] 2> 25019 T59 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@35dcb5a6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@347e543a),segFN=segments_1,generation=1}
[junit4:junit4] 2> 25020 T59 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 25031 T59 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 25032 T59 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 25034 T59 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 25038 T59 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 25044 T59 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 25044 T59 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 25049 T59 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 25052 T59 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 25053 T59 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 25080 T59 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 25098 T59 oass.SolrIndexSearcher.<init> Opening Searcher@30238e7e main
[junit4:junit4] 2> 25099 T59 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.ShardSplitTest-1369655086687\jetty1\tlog
[junit4:junit4] 2> 25104 T59 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 25105 T59 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 25135 T60 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@30238e7e main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 25146 T59 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 25146 T59 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 26815 T39 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 26817 T39 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[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:63710_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63710"}
[junit4:junit4] 2> 26818 T39 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 26818 T39 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 26839 T38 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> 26840 T58 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> 26840 T45 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> 27404 T59 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 27404 T59 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:63710 collection:collection1 shard:shard1
[junit4:junit4] 2> 27406 T59 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 27444 T59 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 27453 T59 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 27454 T59 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 27455 T59 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:63710/collection1/
[junit4:junit4] 2> 27455 T59 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 27456 T59 oasc.SyncStrategy.syncToMe http://127.0.0.1:63710/collection1/ has no replicas
[junit4:junit4] 2> 27456 T59 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:63710/collection1/
[junit4:junit4] 2> 27457 T59 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 28419 T39 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 28449 T38 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> 28451 T58 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> 28451 T45 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> 28483 T59 oasc.ZkController.register We are http://127.0.0.1:63710/collection1/ and leader is http://127.0.0.1:63710/collection1/
[junit4:junit4] 2> 28484 T59 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:63710
[junit4:junit4] 2> 28484 T59 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 28485 T59 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 28485 T59 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 28495 T59 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 28500 T14 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 28501 T14 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 28502 T14 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 28920 T14 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 28925 T14 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:63719
[junit4:junit4] 2> 28926 T14 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 28927 T14 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 28927 T14 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1369655102534
[junit4:junit4] 2> 28927 T14 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1369655102534\solr.xml
[junit4:junit4] 2> 28928 T14 oasc.CoreContainer.<init> New CoreContainer 140437578
[junit4:junit4] 2> 28929 T14 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1369655102534\'
[junit4:junit4] 2> 28930 T14 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1369655102534\'
[junit4:junit4] 2> 29094 T14 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 29094 T14 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 29095 T14 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 29095 T14 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 29096 T14 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 29096 T14 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 29096 T14 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 29098 T14 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 29098 T14 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 29099 T14 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 29109 T14 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 29110 T14 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:63691/solr
[junit4:junit4] 2> 29111 T14 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 29113 T14 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 29133 T72 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3362108e name:ZooKeeperConnection Watcher:127.0.0.1:63691 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 29135 T14 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 29140 T14 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 29158 T14 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 29163 T74 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@58aecf4b name:ZooKeeperConnection Watcher:127.0.0.1:63691/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 29164 T14 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 29177 T14 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 30039 T39 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 30042 T39 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[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:63710_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63710"}
[junit4:junit4] 2> 30054 T74 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> 30056 T38 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> 30058 T58 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> 30059 T45 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> 30220 T14 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63719_
[junit4:junit4] 2> 30225 T14 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:63719_
[junit4:junit4] 2> 30232 T74 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> 30233 T38 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> 30234 T45 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> 30237 T58 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 30238 T58 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> 30246 T74 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 30248 T38 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 30250 T45 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 30260 T75 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1369655102534\collection1
[junit4:junit4] 2> 30262 T75 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 30263 T75 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 30263 T75 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 30267 T75 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1369655102534\collection1\'
[junit4:junit4] 2> 30268 T75 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1369655102534/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 30268 T75 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1369655102534/collection1/lib/README' to classloader
[junit4:junit4] 2> 30337 T75 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 30424 T75 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 30428 T75 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 30468 T75 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 31262 T75 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 31266 T75 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 31270 T75 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 31277 T75 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 31358 T75 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 31359 T75 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty2-1369655102534\collection1\, dataDir=.\org.apache.solr.cloud.ShardSplitTest-1369655086687/jetty2\
[junit4:junit4] 2> 31359 T75 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5ebd50b9
[junit4:junit4] 2> 31360 T75 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 31360 T75 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1369655086687/jetty2\
[junit4:junit4] 2> 31361 T75 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardSplitTest-1369655086687/jetty2\index/
[junit4:junit4] 2> 31362 T75 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ShardSplitTest-1369655086687\jetty2\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 31363 T75 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1369655086687/jetty2\index
[junit4:junit4] 2> 31368 T75 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@35bf3208 lockFactory=org.apache.lucene.store.NativeFSLockFactory@71034e3b),segFN=segments_1,generation=1}
[junit4:junit4] 2> 31368 T75 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 31373 T75 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 31374 T75 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 31375 T75 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 31376 T75 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 31379 T75 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 31379 T75 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 31380 T75 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 31381 T75 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 31382 T75 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 31398 T75 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 31408 T75 oass.SolrIndexSearcher.<init> Opening Searcher@5b07e4df main
[junit4:junit4] 2> 31409 T75 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.ShardSplitTest-1369655086687\jetty2\tlog
[junit4:junit4] 2> 31411 T75 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 31412 T75 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 31431 T75 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 31431 T75 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 31436 T76 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5b07e4df main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 31630 T39 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 31632 T39 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[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:63719_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63719"}
[junit4:junit4] 2> 31633 T39 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 31634 T39 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 31646 T74 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> 31647 T38 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> 31648 T58 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> 31648 T45 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> 32479 T75 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 32479 T75 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:63719 collection:collection1 shard:shard2
[junit4:junit4] 2> 32482 T75 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 32507 T75 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 32518 T75 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 32519 T75 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 32520 T75 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:63719/collection1/
[junit4:junit4] 2> 32521 T75 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 32521 T75 oasc.SyncStrategy.syncToMe http://127.0.0.1:63719/collection1/ has no replicas
[junit4:junit4] 2> 32522 T75 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:63719/collection1/
[junit4:junit4] 2> 32522 T75 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 33216 T39 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 33249 T74 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> 33251 T38 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> 33251 T58 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> 33251 T45 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> 33282 T75 oasc.ZkController.register We are http://127.0.0.1:63719/collection1/ and leader is http://127.0.0.1:63719/collection1/
[junit4:junit4] 2> 33282 T75 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:63719
[junit4:junit4] 2> 33283 T75 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 33284 T75 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 33284 T75 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 33289 T75 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 33292 T14 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 33292 T14 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 33293 T14 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 33800 T14 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 33804 T14 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:63728
[junit4:junit4] 2> 33806 T14 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 33807 T14 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 33807 T14 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1369655107322
[junit4:junit4] 2> 33808 T14 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1369655107322\solr.xml
[junit4:junit4] 2> 33808 T14 oasc.CoreContainer.<init> New CoreContainer 12026463
[junit4:junit4] 2> 33809 T14 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1369655107322\'
[junit4:junit4] 2> 33809 T14 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1369655107322\'
[junit4:junit4] 2> 33947 T14 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 33947 T14 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 33948 T14 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 33948 T14 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 33949 T14 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 33949 T14 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 33950 T14 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 33950 T14 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 33951 T14 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 33952 T14 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 33961 T14 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 33962 T14 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:63691/solr
[junit4:junit4] 2> 33962 T14 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 33964 T14 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 33981 T88 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2d913d11 name:ZooKeeperConnection Watcher:127.0.0.1:63691 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 33982 T14 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 33987 T14 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 33987 T16 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13ee5ce0f780009, likely client has closed socket
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2>
[junit4:junit4] 2> 33996 T14 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 34000 T90 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4926aaf7 name:ZooKeeperConnection Watcher:127.0.0.1:63691/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 34001 T14 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 34013 T14 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 34828 T39 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 34831 T39 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[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:63719_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63719"}
[junit4:junit4] 2> 34847 T74 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> 34848 T38 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> 34848 T58 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> 34849 T90 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> 34852 T45 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> 35057 T14 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63728_
[junit4:junit4] 2> 35061 T14 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:63728_
[junit4:junit4] 2> 35066 T74 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> 35068 T38 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> 35070 T45 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> 35071 T58 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 35071 T58 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> 35074 T90 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 35075 T90 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> 35083 T74 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 35086 T38 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 35088 T45 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 35101 T91 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1369655107322\collection1
[junit4:junit4] 2> 35101 T91 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 35103 T91 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 35103 T91 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 35107 T91 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1369655107322\collection1\'
[junit4:junit4] 2> 35109 T91 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1369655107322/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 35110 T91 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1369655107322/collection1/lib/README' to classloader
[junit4:junit4] 2> 35206 T91 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 35289 T91 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 35298 T91 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 35325 T91 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 36160 T91 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 36167 T91 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 36170 T91 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 36178 T91 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 36281 T91 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 36282 T91 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty3-1369655107322\collection1\, dataDir=.\org.apache.solr.cloud.ShardSplitTest-1369655086687/jetty3\
[junit4:junit4] 2> 36283 T91 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5ebd50b9
[junit4:junit4] 2> 36284 T91 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 36285 T91 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1369655086687/jetty3\
[junit4:junit4] 2> 36285 T91 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardSplitTest-1369655086687/jetty3\index/
[junit4:junit4] 2> 36286 T91 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ShardSplitTest-1369655086687\jetty3\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 36287 T91 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1369655086687/jetty3\index
[junit4:junit4] 2> 36294 T91 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@548f2dd2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2129a843),segFN=segments_1,generation=1}
[junit4:junit4] 2> 36295 T91 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 36305 T91 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 36306 T91 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 36309 T91 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 36311 T91 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 36314 T91 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 36314 T91 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 36315 T91 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 36318 T91 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 36319 T91 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 36338 T91 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 36346 T91 oass.SolrIndexSearcher.<init> Opening Searcher@35b0b7f main
[junit4:junit4] 2> 36347 T91 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.ShardSplitTest-1369655086687\jetty3\tlog
[junit4:junit4] 2> 36348 T91 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 36348 T91 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 36359 T92 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@35b0b7f main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 36368 T91 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 36368 T91 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 36418 T39 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 36420 T39 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"4",
[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:63728_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63728"}
[junit4:junit4] 2> 36420 T39 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 36421 T39 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 36433 T74 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> 36434 T38 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> 36434 T58 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> 36434 T90 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> 36435 T45 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> 37402 T91 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 37402 T91 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:63728 collection:collection1 shard:shard1
[junit4:junit4] 2> 37417 T91 oasc.ZkController.register We are http://127.0.0.1:63728/collection1/ and leader is http://127.0.0.1:63710/collection1/
[junit4:junit4] 2> 37417 T91 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:63728
[junit4:junit4] 2> 37418 T91 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 37418 T91 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C31 name=collection1 org.apache.solr.core.SolrCore@5bc5960f url=http://127.0.0.1:63728/collection1 node=127.0.0.1:63728_ C31_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:63728_, base_url=http://127.0.0.1:63728}
[junit4:junit4] 2> 37424 T93 C31 P63728 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 37426 T93 C31 P63728 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 37426 T91 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 37426 T93 C31 P63728 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 37427 T93 C31 P63728 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 37429 T14 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 37429 T14 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 37430 T14 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 37432 T93 C31 P63728 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 37936 T39 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 37938 T39 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"4",
[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:63728_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63728"}
[junit4:junit4] 2> 37995 T74 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> 37996 T38 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> 38004 T58 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> 38006 T90 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> 38007 T45 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> 38011 T14 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 38020 T14 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:63737
[junit4:junit4] 2> 38021 T14 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 38021 T14 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 38021 T14 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty4-1369655111460
[junit4:junit4] 2> 38022 T14 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty4-1369655111460\solr.xml
[junit4:junit4] 2> 38023 T14 oasc.CoreContainer.<init> New CoreContainer 1349117486
[junit4:junit4] 2> 38023 T14 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty4-1369655111460\'
[junit4:junit4] 2> 38024 T14 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty4-1369655111460\'
[junit4:junit4] 2> 38384 T14 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 38384 T14 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 38385 T14 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 38385 T14 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 38385 T14 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 38387 T14 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 38388 T14 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 38389 T14 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 38389 T14 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 38390 T14 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 38398 T14 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 38400 T14 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:63691/solr
[junit4:junit4] 2> 38400 T14 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 38413 T14 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 38434 T107 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@f3d6fa4 name:ZooKeeperConnection Watcher:127.0.0.1:63691 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 38435 T14 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 38459 T14 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 38473 T14 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 38495 T109 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@28733484 name:ZooKeeperConnection Watcher:127.0.0.1:63691/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 38496 T14 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 38527 T14 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 38744 T50 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 4, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 38747 T50 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 4, state: recovering, checkLive: true, onlyIfLeader: true for: 0 seconds.
[junit4:junit4] 2> 38749 T50 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=4&state=recovering&nodeName=127.0.0.1:63728_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=10
[junit4:junit4] 2> 39475 T14 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63737_
[junit4:junit4] 2> 39479 T14 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:63737_
[junit4:junit4] 2> 39484 T74 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> 39487 T45 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> 39490 T38 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> 39493 T90 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 39493 T90 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> 39496 T58 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 39496 T58 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> 39499 T109 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 39501 T74 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 39507 T45 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 39510 T38 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 39525 T110 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty4-1369655111460\collection1
[junit4:junit4] 2> 39525 T110 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 39528 T110 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 39528 T110 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 39533 T110 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty4-1369655111460\collection1\'
[junit4:junit4] 2> 39538 T110 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty4-1369655111460/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 39541 T110 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty4-1369655111460/collection1/lib/README' to classloader
[junit4:junit4] 2> 39651 T110 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 39722 T110 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 39724 T110 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 39744 T110 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 40522 T110 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 40528 T110 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 40530 T110 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 40539 T110 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 40639 T110 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 40639 T110 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ShardSplitTest-jetty4-1369655111460\collection1\, dataDir=.\org.apache.solr.cloud.ShardSplitTest-1369655086687/jetty4\
[junit4:junit4] 2> 40640 T110 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5ebd50b9
[junit4:junit4] 2> 40642 T110 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 40642 T110 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1369655086687/jetty4\
[junit4:junit4] 2> 40642 T110 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ShardSplitTest-1369655086687/jetty4\index/
[junit4:junit4] 2> 40643 T110 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ShardSplitTest-1369655086687\jetty4\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 40648 T110 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1369655086687/jetty4\index
[junit4:junit4] 2> 40652 T110 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3e52f2e5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@404c6509),segFN=segments_1,generation=1}
[junit4:junit4] 2> 40652 T110 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 40656 T110 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 40656 T110 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 40658 T110 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 40659 T110 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 40660 T110 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 40660 T110 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 40661 T110 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 40662 T110 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 40662 T110 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 40672 T110 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 40683 T110 oass.SolrIndexSearcher.<init> Opening Searcher@2014b5af main
[junit4:junit4] 2> 40683 T110 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.ShardSplitTest-1369655086687\jetty4\tlog
[junit4:junit4] 2> 40685 T110 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 40686 T110 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 40697 T110 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 40697 T110 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 40705 T111 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2014b5af main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> ASYNC NEW_CORE C32 name=collection1 org.apache.solr.core.SolrCore@5bc5960f url=http://127.0.0.1:63728/collection1 node=127.0.0.1:63728_ C32_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:63728_, base_url=http://127.0.0.1:63728}
[junit4:junit4] 2> 40741 T93 C32 P63728 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:63710/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 40757 T93 C32 P63728 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&connTimeout=30000&socketTimeout=30000&retry=false
[junit4:junit4] 2> 40781 T93 C32 P63728 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:63728 START replicas=[http://127.0.0.1:63710/collection1/] nUpdates=100
[junit4:junit4] 2> 40789 T93 C32 P63728 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 40790 T93 C32 P63728 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 40790 T93 C32 P63728 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 40790 T93 C32 P63728 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 40790 T93 C32 P63728 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 40791 T93 C32 P63728 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:63710/collection1/. core=collection1
[junit4:junit4] 2> 40791 T93 C32 P63728 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C33 name=collection1 org.apache.solr.core.SolrCore@4fb7a0d3 url=http://127.0.0.1:63710/collection1 node=127.0.0.1:63710_ C33_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:63710_, base_url=http://127.0.0.1:63710, leader=true}
[junit4:junit4] 2> 40833 T51 C33 P63710 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=5
[junit4:junit4] 2> 40848 T50 C33 P63710 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 40852 T50 C33 P63710 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@35dcb5a6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@347e543a),segFN=segments_1,generation=1}
[junit4:junit4] 2> 40853 T50 C33 P63710 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 40855 T50 C33 P63710 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@35dcb5a6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@347e543a),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@35dcb5a6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@347e543a),segFN=segments_2,generation=2}
[junit4:junit4] 2> 40856 T50 C33 P63710 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 40856 T50 C33 P63710 oass.SolrIndexSearcher.<init> Opening Searcher@5919e0a8 realtime
[junit4:junit4] 2> 40856 T50 C33 P63710 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 40857 T50 C33 P63710 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 27
[junit4:junit4] 2> 40901 T39 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 40904 T39 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"5",
[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:63737_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63737"}
[junit4:junit4] 2> 40905 T39 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 40906 T39 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 40909 T93 C32 P63728 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 40910 T93 C32 P63728 oascsi.HttpClientUtil.createClient Creating new http client, config:connTimeout=5000&socketTimeout=20000&allowCompression=false&maxConnections=10000&maxConnectionsPerHost=10000
[junit4:junit4] 2> 40928 T109 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> 40929 T45 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> 40930 T74 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> 40930 T93 C32 P63728 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 40930 T90 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> 40930 T58 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> 40930 T38 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> ASYNC NEW_CORE C34 name=collection1 org.apache.solr.core.SolrCore@4fb7a0d3 url=http://127.0.0.1:63710/collection1 node=127.0.0.1:63710_ C34_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:63710_, base_url=http://127.0.0.1:63710, leader=true}
[junit4:junit4] 2> 40994 T53 C34 P63710 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 40995 T53 C34 P63710 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=57
[junit4:junit4] 2> ASYNC NEW_CORE C35 name=collection1 org.apache.solr.core.SolrCore@5bc5960f url=http://127.0.0.1:63728/collection1 node=127.0.0.1:63728_ C35_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:63728_, base_url=http://127.0.0.1:63728}
[junit4:junit4] 2> 40997 T93 C35 P63728 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 40998 T93 C35 P63728 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 40998 T93 C35 P63728 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 41003 T54 C34 P63710 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> 41004 T93 C35 P63728 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 41006 T93 C35 P63728 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1369655086687/jetty3\index.20130527024515025
[junit4:junit4] 2> 41006 T93 C35 P63728 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@5b546fb7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@667507f4) fullCopy=false
[junit4:junit4] 2> 41017 T49 C34 P63710 oasc.SolrCore.execute [collection1] webapp= path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=4
[junit4:junit4] 2> 41038 T93 C35 P63728 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 41044 T93 C35 P63728 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 41044 T93 C35 P63728 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 41057 T93 C35 P63728 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@548f2dd2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2129a843),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@548f2dd2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2129a843),segFN=segments_2,generation=2}
[junit4:junit4] 2> 41057 T93 C35 P63728 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 41058 T93 C35 P63728 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 41059 T93 C35 P63728 oass.SolrIndexSearcher.<init> Opening Searcher@7c055ac2 main
[junit4:junit4] 2> 41061 T92 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7c055ac2 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 41061 T93 C35 P63728 oasc.CachingDirectoryFactory.closeCacheValue looking to close .\org.apache.solr.cloud.ShardSplitTest-1369655086687/jetty3\index.20130527024515025 [CachedDir<<refCount=0;path=.\org.apache.solr.cloud.ShardSplitTest-1369655086687/jetty3\index.20130527024515025;done=true>>]
[junit4:junit4] 2> 41062 T93 C35 P63728 oasc.CachingDirectoryFactory.close Closing directory: .\org.apache.solr.cloud.ShardSplitTest-1369655086687/jetty3\index.20130527024515025
[junit4:junit4] 2> 41062 T93 C35 P63728 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: .\org.apache.solr.cloud.ShardSplitTest-1369655086687/jetty3\index.20130527024515025
[junit4:junit4] 2> 41063 T93 C35 P63728 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 41063 T93 C35 P63728 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 41071 T93 C35 P63728 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 41071 T93 C35 P63728 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 41075 T93 C35 P63728 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 41643 T110 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 41644 T110 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:63737 collection:collection1 shard:shard2
[junit4:junit4] 2> 41659 T110 oasc.ZkController.register We are http://127.0.0.1:63737/collection1/ and leader is http://127.0.0.1:63719/collection1/
[junit4:junit4] 2> 41659 T110 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:63737
[junit4:junit4] 2> 41660 T110 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 41660 T110 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C36 name=collection1 org.apache.solr.core.SolrCore@27db5a86 url=http://127.0.0.1:63737/collection1 node=127.0.0.1:63737_ C36_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:63737_, base_url=http://127.0.0.1:63737}
[junit4:junit4] 2> 41663 T114 C36 P63737 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 41665 T114 C36 P63737 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 41666 T114 C36 P63737 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 41667 T114 C36 P63737 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 41666 T110 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 41675 T114 C36 P63737 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 41678 T14 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 41680 T14 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 41682 T14 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 41691 T66 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 41692 T14 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 41695 T14 oasc.AbstractFullDistribZkTestBase.waitForThingsToLevelOut Wait for recoveries to finish - wait 15 for each attempt
[junit4:junit4] 2> 41695 T14 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):15
[junit4:junit4] 2> 41698 T14 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 42367 T39 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 42370 T39 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"4",
[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:63728_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63728"}
[junit4:junit4] 2> 42388 T39 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"5",
[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:63737_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63737"}
[junit4:junit4] 2> 42400 T74 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> 42402 T38 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> 42403 T58 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> 42404 T90 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> 42406 T109 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> 42407 T45 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> 42625 T66 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 42626 T66 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=5&state=recovering&nodeName=127.0.0.1:63737_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=935
[junit4:junit4] 2> 42633 T14 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 43570 T14 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> C36_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:63737_, base_url=http://127.0.0.1:63737}
[junit4:junit4] 2> 44493 T114 C36 P63737 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:63719/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 44493 T114 C36 P63737 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:63737 START replicas=[http://127.0.0.1:63719/collection1/] nUpdates=100
[junit4:junit4] 2> 44494 T114 C36 P63737 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 44494 T114 C36 P63737 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 44497 T114 C36 P63737 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 44497 T114 C36 P63737 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 44497 T114 C36 P63737 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 44497 T114 C36 P63737 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:63719/collection1/. core=collection1
[junit4:junit4] 2> 44501 T114 C36 P63737 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 44520 T14 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> ASYNC NEW_CORE C37 name=collection1 org.apache.solr.core.SolrCore@189e8b21 url=http://127.0.0.1:63719/collection1 node=127.0.0.1:63719_ C37_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:63719_, base_url=http://127.0.0.1:63719, leader=true}
[junit4:junit4] 2> 44525 T67 C37 P63719 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 44530 T68 C37 P63719 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 44536 T68 C37 P63719 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@35bf3208 lockFactory=org.apache.lucene.store.NativeFSLockFactory@71034e3b),segFN=segments_1,generation=1}
[junit4:junit4] 2> 44536 T68 C37 P63719 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 44538 T68 C37 P63719 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@35bf3208 lockFactory=org.apache.lucene.store.NativeFSLockFactory@71034e3b),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@35bf3208 lockFactory=org.apache.lucene.store.NativeFSLockFactory@71034e3b),segFN=segments_2,generation=2}
[junit4:junit4] 2> 44538 T68 C37 P63719 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 44538 T68 C37 P63719 oass.SolrIndexSearcher.<init> Opening Searcher@3dd1c356 realtime
[junit4:junit4] 2> 44538 T68 C37 P63719 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 44538 T68 C37 P63719 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 10
[junit4:junit4] 2> ASYNC NEW_CORE C38 name=collection1 org.apache.solr.core.SolrCore@27db5a86 url=http://127.0.0.1:63737/collection1 node=127.0.0.1:63737_ C38_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:63737_, base_url=http://127.0.0.1:63737}
[junit4:junit4] 2> 44542 T114 C38 P63737 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 44543 T114 C38 P63737 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 44547 T69 C37 P63719 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 44548 T69 C37 P63719 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=2
[junit4:junit4] 2> 44548 T114 C38 P63737 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 44549 T114 C38 P63737 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 44549 T114 C38 P63737 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 44553 T70 C37 P63719 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> 44555 T114 C38 P63737 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 44557 T114 C38 P63737 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ShardSplitTest-1369655086687/jetty4\index.20130527024518577
[junit4:junit4] 2> 44558 T114 C38 P63737 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@47b42535 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7fc42635) fullCopy=false
[junit4:junit4] 2> 44561 T65 C37 P63719 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> 44564 T114 C38 P63737 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 44566 T114 C38 P63737 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 44567 T114 C38 P63737 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 44573 T114 C38 P63737 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3e52f2e5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@404c6509),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3e52f2e5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@404c6509),segFN=segments_2,generation=2}
[junit4:junit4] 2> 44574 T114 C38 P63737 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 44575 T114 C38 P63737 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 44575 T114 C38 P63737 oass.SolrIndexSearcher.<init> Opening Searcher@3d31ef93 main
[junit4:junit4] 2> 44577 T111 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3d31ef93 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 44579 T114 C38 P63737 oasc.CachingDirectoryFactory.closeCacheValue looking to close .\org.apache.solr.cloud.ShardSplitTest-1369655086687/jetty4\index.20130527024518577 [CachedDir<<refCount=0;path=.\org.apache.solr.cloud.ShardSplitTest-1369655086687/jetty4\index.20130527024518577;done=true>>]
[junit4:junit4] 2> 44579 T114 C38 P63737 oasc.CachingDirectoryFactory.close Closing directory: .\org.apache.solr.cloud.ShardSplitTest-1369655086687/jetty4\index.20130527024518577
[junit4:junit4] 2> 44582 T114 C38 P63737 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: .\org.apache.solr.cloud.ShardSplitTest-1369655086687/jetty4\index.20130527024518577
[junit4:junit4] 2> 44582 T114 C38 P63737 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 44582 T114 C38 P63737 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 44582 T114 C38 P63737 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 44582 T114 C38 P63737 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 44589 T114 C38 P63737 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 45231 T39 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 45232 T39 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"5",
[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:63737_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63737"}
[junit4:junit4] 2> 45248 T74 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> 45249 T38 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> 45250 T58 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> 45250 T90 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> 45254 T109 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> 45254 T45 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> 45463 T14 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 45465 T14 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: collection1
[junit4:junit4] 2> ASYNC NEW_CORE C39 name=collection1 org.apache.solr.core.SolrCore@7e1888b2 url=http://127.0.0.1:63698/collection1 node=127.0.0.1:63698_ C39_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:63698_, base_url=http://127.0.0.1:63698, leader=true}
[junit4:junit4] 2> 45475 T32 C39 P63698 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 45477 T32 C39 P63698 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@73b58165 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3e6bb568),segFN=segments_1,generation=1}
[junit4:junit4] 2> 45479 T32 C39 P63698 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 45479 T32 C39 P63698 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@73b58165 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3e6bb568),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@73b58165 lockFactory=org.apache.lucene.store.NativeFSLockFactory@3e6bb568),segFN=segments_2,generation=2}
[junit4:junit4] 2> 45480 T32 C39 P63698 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 45480 T32 C39 P63698 oass.SolrIndexSearcher.<init> Opening Searcher@136833f0 main
[junit4:junit4] 2> 45480 T32 C39 P63698 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 45482 T42 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@136833f0 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 45483 T32 C39 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 9
[junit4:junit4] 2> 45500 T66 C37 P63719 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 45501 T66 C37 P63719 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@35bf3208 lockFactory=org.apache.lucene.store.NativeFSLockFactory@71034e3b),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@35bf3208 lockFactory=org.apache.lucene.store.NativeFSLockFactory@71034e3b),segFN=segments_3,generation=3}
[junit4:junit4] 2> 45501 T66 C37 P63719 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 45502 T66 C37 P63719 oass.SolrIndexSearcher.<init> Opening Searcher@5f81a1f3 main
[junit4:junit4] 2> 45503 T66 C37 P63719 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 45504 T76 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5f81a1f3 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 45514 T66 C37 P63719 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:63710/collection1/, StdNode: http://127.0.0.1:63728/collection1/, StdNode: http://127.0.0.1:63737/collection1/] params:commit_end_point=true&commit=true&softCommit=false&waitSearcher=true&expungeDeletes=false
[junit4:junit4] 2> ASYNC NEW_CORE C40 name=collection1 org.apache.solr.core.SolrCore@4fb7a0d3 url=http://127.0.0.1:63710/collection1 node=127.0.0.1:63710_ C40_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:63710_, base_url=http://127.0.0.1:63710, leader=true}
[junit4:junit4] 2> 45532 T51 C40 P63710 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 45535 T51 C40 P63710 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@35dcb5a6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@347e543a),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@35dcb5a6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@347e543a),segFN=segments_3,generation=3}
[junit4:junit4] 2> 45539 T51 C40 P63710 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> ASYNC NEW_CORE C41 name=collection1 org.apache.solr.core.SolrCore@5bc5960f url=http://127.0.0.1:63728/collection1 node=127.0.0.1:63728_ C41_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:63728_, base_url=http://127.0.0.1:63728}
[junit4:junit4] 2> 45553 T81 C41 P63728 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> ASYNC NEW_CORE C42 name=collection1 org.apache.solr.core.SolrCore@4fb7a0d3 url=http://127.0.0.1:63710/collection1 node=127.0.0.1:63710_ C42_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:63710_, base_url=http://127.0.0.1:63710, leader=true}
[junit4:junit4] 2> 45553 T51 C42 P63710 oass.SolrIndexSearcher.<init> Opening Searcher@6bdb0097 main
[junit4:junit4] 2> 45558 T81 C41 P63728 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@548f2dd2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2129a843),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@548f2dd2 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2129a843),segFN=segments_3,generation=3}
[junit4:junit4] 2> ASYNC NEW_CORE C43 name=collection1 org.apache.solr.core.SolrCore@27db5a86 url=http://127.0.0.1:63737/collection1 node=127.0.0.1:63737_ C43_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:63737_, base_url=http://127.0.0.1:63737}
[junit4:junit4] 2> 45553 T104 C43 P63737 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 45559 T81 C41 P63728 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 45558 T51 C42 P63710 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 45561 T60 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6bdb0097 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 45562 T104 C43 P63737 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3e52f2e5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@404c6509),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3e52f2e5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@404c6509),segFN=segments_3,generation=3}
[junit4:junit4] 2> 45562 T104 C43 P63737 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 45563 T51 C42 P63710 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 31
[junit4:junit4] 2> 45562 T81 C41 P63728 oass.SolrIndexSearcher.<init> Opening Searcher@7ec2d0d0 main
[junit4:junit4] 2> 45565 T81 C41 P63728 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 45565 T104 C43 P63737 oass.SolrIndexSearcher.<init> Opening Searcher@7e3a325b main
[junit4:junit4] 2> 45566 T104 C43 P63737 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 45569 T111 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7e3a325b main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 45567 T92 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7ec2d0d0 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 45571 T81 C41 P63728 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 18
[junit4:junit4] 2> 45571 T104 C43 P63737 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 18
[junit4:junit4] 2> ASYNC NEW_CORE C44 name=collection1 org.apache.solr.core.SolrCore@189e8b21 url=http://127.0.0.1:63719/collection1 node=127.0.0.1:63719_ C44_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:63719_, base_url=http://127.0.0.1:63719, leader=true}
[junit4:junit4] 2> 45572 T66 C44 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 72
[junit4:junit4] 2> 45574 T14 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 45592 T52 C42 P63710 oasc.SolrCore.execute [collection1] webapp= path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=5
[junit4:junit4] 2> 45596 T83 C41 P63728 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> 45600 T69 C44 P63719 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> 45603 T102 C43 P63737 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> ASYNC NEW_CORE C45 name=collection1 org.apache.solr.core.SolrCore@7e1888b2 url=http://127.0.0.1:63698/collection1 node=127.0.0.1:63698_ C45_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:63698_, base_url=http://127.0.0.1:63698, leader=true}
[junit4:junit4] 2> 47493 T29 C45 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1436187488649478144)} 0 61
[junit4:junit4] 2> 47509 T82 C41 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={update.distrib=FROMLEADER&_version_=-1436187488700858368&update.from=http://127.0.0.1:63710/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1436187488700858368)} 0 3
[junit4:junit4] 2> 47514 T101 C43 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={update.distrib=FROMLEADER&_version_=-1436187488710295552&update.from=http://127.0.0.1:63719/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1436187488710295552)} 0 2
[junit4:junit4] 2> 47515 T68 C44 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={update.distrib=TOLEADER&wt=javabin&version=2} {deleteByQuery=*:* (-1436187488710295552)} 0 9
[junit4:junit4] 2> 47516 T50 C42 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1436187488700858368)} 0 19
[junit4:junit4] 2> 47551 T31 C45 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[a!0 (1436187488731267072)]} 0 32
[junit4:junit4] 2> 47581 T97 C43 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[a!0 (1436187488780550144)]} 0 3
[junit4:junit4] 2> 47583 T66 C44 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[a!0 (1436187488780550144)]} 0 10
[junit4:junit4] 2> 47583 T51 C42 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[a!0]} 0 27
[junit4:junit4] 2> 47589 T32 C45 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[b!1 (1436187488796278784)]} 0 1
[junit4:junit4] 2> 47603 T81 C41 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[b!1 (1436187488804667392)]} 0 2
[junit4:junit4] 2> 47605 T52 C42 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[b!1 (1436187488804667392)]} 0 9
[junit4:junit4] 2> 47606 T69 C44 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[b!1]} 0 14
[junit4:junit4] 2> 47610 T33 C45 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[c!2 (1436187488819347456)]} 0 0
[junit4:junit4] 2> 47618 T83 C41 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[c!2 (1436187488823541760)]} 0 1
[junit4:junit4] 2> ASYNC NEW_CORE C46 name=collection1 org.apache.solr.core.SolrCore@4fb7a0d3 url=http://127.0.0.1:63710/collection1 node=127.0.0.1:63710_ C46_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:63710_, base_url=http://127.0.0.1:63710, leader=true}
[junit4:junit4] 2> 47628 T53 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[c!2 (1436187488823541760)]} 0 14
[junit4:junit4] 2> ASYNC NEW_CORE C47 name=collection1 org.apache.solr.core.SolrCore@7e1888b2 url=http://127.0.0.1:63698/collection1 node=127.0.0.1:63698_ C47_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:63698_, base_url=http://127.0.0.1:63698, leader=true}
[junit4:junit4] 2> 47633 T34 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[d!3 (1436187488843464704)]} 0 1
[junit4:junit4] 2> ASYNC NEW_CORE C48 name=collection1 org.apache.solr.core.SolrCore@27db5a86 url=http://127.0.0.1:63737/collection1 node=127.0.0.1:63737_ C48_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:63737_, base_url=http://127.0.0.1:63737}
[junit4:junit4] 2> 47645 T104 C48 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[d!3 (1436187488847659008)]} 0 3
[junit4:junit4] 2> ASYNC NEW_CORE C49 name=collection1 org.apache.solr.core.SolrCore@189e8b21 url=http://127.0.0.1:63719/collection1 node=127.0.0.1:63719_ C49_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:63719_, base_url=http://127.0.0.1:63719, leader=true}
[junit4:junit4] 2> 47646 T70 C49 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[d!3 (1436187488847659008)]} 0 9
[junit4:junit4] 2> 47651 T30 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[e!4 (1436187488862339072)]} 0 0
[junit4:junit4] 2> 47664 T102 C48 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[e!4 (1436187488870727680)]} 0 0
[junit4:junit4] 2> 47666 T65 C49 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[e!4 (1436187488870727680)]} 0 7
[junit4:junit4] 2> 47668 T54 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[e!4]} 0 13
[junit4:junit4] 2> 47673 T29 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[f!5 (1436187488883310592)]} 0 2
[junit4:junit4] 2> 47688 T100 C48 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[f!5 (1436187488893796352)]} 0 4
[junit4:junit4] 2> 47690 T67 C49 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[f!5 (1436187488893796352)]} 0 9
[junit4:junit4] 2> 47691 T49 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[f!5]} 0 14
[junit4:junit4] 2> 47697 T31 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[g!6 (1436187488908476416)]} 0 2
[junit4:junit4] 2> ASYNC NEW_CORE C50 name=collection1 org.apache.solr.core.SolrCore@5bc5960f url=http://127.0.0.1:63728/collection1 node=127.0.0.1:63728_ C50_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:63728_, base_url=http://127.0.0.1:63728}
[junit4:junit4] 2> 47718 T84 C50 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[g!6 (1436187488921059328)]} 0 2
[junit4:junit4] 2> 47719 T50 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[g!6 (1436187488921059328)]} 0 12
[junit4:junit4] 2> 47720 T68 C49 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[g!6]} 0 19
[junit4:junit4] 2> 47729 T32 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[h!7 (1436187488943079424)]} 0 1
[junit4:junit4] 2> 47747 T85 C50 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[h!7 (1436187488952516608)]} 0 1
[junit4:junit4] 2> 47749 T51 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[h!7 (1436187488952516608)]} 0 12
[junit4:junit4] 2> 47752 T33 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[i!8 (1436187488968245248)]} 0 1
[junit4:junit4] 2> 47764 T86 C50 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[i!8 (1436187488975585280)]} 0 1
[junit4:junit4] 2> 47768 T52 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[i!8 (1436187488975585280)]} 0 10
[junit4:junit4] 2> 47769 T66 C49 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[i!8]} 0 14
[junit4:junit4] 2> 47773 T34 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[j!9 (1436187488990265344)]} 0 0
[junit4:junit4] 2> 47785 T82 C50 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[j!9 (1436187488997605376)]} 0 1
[junit4:junit4] 2> 47787 T53 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[j!9 (1436187488997605376)]} 0 8
[junit4:junit4] 2> 47789 T69 C49 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[j!9]} 0 13
[junit4:junit4] 2> 47793 T30 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[k!10 (1436187489011236864)]} 0 1
[junit4:junit4] 2> 47805 T83 C50 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[k!10 (1436187489018576896)]} 0 0
[junit4:junit4] 2> 47818 T49 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[k!10 (1436187489018576896)]} 0 18
[junit4:junit4] 2> 47818 T65 C49 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[k!10]} 0 22
[junit4:junit4] 2> 47823 T29 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[l!11 (1436187489042694144)]} 0 0
[junit4:junit4] 2> 47833 T99 C48 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[l!11 (1436187489050034176)]} 0 1
[junit4:junit4] 2> 47835 T67 C49 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[l!11 (1436187489050034176)]} 0 5
[junit4:junit4] 2> 47836 T50 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[l!11]} 0 9
[junit4:junit4] 2> 47840 T32 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[m!12 (1436187489060519936)]} 0 1
[junit4:junit4] 2> 47848 T101 C48 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[m!12 (1436187489064714240)]} 0 0
[junit4:junit4] 2> 47850 T68 C49 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[m!12 (1436187489064714240)]} 0 7
[junit4:junit4] 2> 47858 T33 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[n!13 (1436187489074151424)]} 0 6
[junit4:junit4] 2> 47866 T84 C50 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[n!13 (1436187489083588608)]} 0 1
[junit4:junit4] 2> 47867 T51 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[n!13 (1436187489083588608)]} 0 6
[junit4:junit4] 2> 47872 T34 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[o!14 (1436187489093025792)]} 0 1
[junit4:junit4] 2> 47879 T97 C48 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[o!14 (1436187489098268672)]} 0 1
[junit4:junit4] 2> 47882 T66 C49 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[o!14 (1436187489098268672)]} 0 6
[junit4:junit4] 2> 47889 T30 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[p!15 (1436187489111900160)]} 0 1
[junit4:junit4] 2> 47899 T85 C50 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[p!15 (1436187489118191616)]} 0 1
[junit4:junit4] 2> 47900 T52 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[p!15 (1436187489118191616)]} 0 5
[junit4:junit4] 2> 47904 T69 C49 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[p!15]} 0 12
[junit4:junit4] 2> 47915 T29 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[q!16 (1436187489138114560)]} 0 0
[junit4:junit4] 2> 47922 T86 C50 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[q!16 (1436187489142308864)]} 0 1
[junit4:junit4] 2> 47923 T53 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[q!16 (1436187489142308864)]} 0 5
[junit4:junit4] 2> 47938 T31 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[r!17 (1436187489163280384)]} 0 0
[junit4:junit4] 2> 47946 T104 C48 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[r!17 (1436187489167474688)]} 0 1
[junit4:junit4] 2> 47948 T70 C49 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[r!17 (1436187489167474688)]} 0 7
[junit4:junit4] 2> 47951 T32 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[s!18 (1436187489176911872)]} 0 1
[junit4:junit4] 2> 47965 T82 C50 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[s!18 (1436187489188446208)]} 0 1
[junit4:junit4] 2> 47967 T54 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[s!18 (1436187489188446208)]} 0 6
[junit4:junit4] 2> 47970 T33 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[t!19 (1436187489196834816)]} 0 1
[junit4:junit4] 2> 47981 T81 C50 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[t!19 (1436187489204174848)]} 0 0
[junit4:junit4] 2> 47982 T49 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[t!19 (1436187489204174848)]} 0 5
[junit4:junit4] 2> 47984 T65 C49 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[t!19]} 0 11
[junit4:junit4] 2> 47987 T34 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[u!20 (1436187489214660608)]} 0 0
[junit4:junit4] 2> 48016 T102 C48 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[u!20 (1436187489239826432)]} 0 1
[junit4:junit4] 2> 48018 T67 C49 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[u!20 (1436187489239826432)]} 0 8
[junit4:junit4] 2> 48019 T50 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[u!20]} 0 12
[junit4:junit4] 2> 48024 T30 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[v!21 (1436187489253457920)]} 0 1
[junit4:junit4] 2> 48047 T83 C50 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[v!21 (1436187489272332288)]} 0 2
[junit4:junit4] 2> 48048 T51 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[v!21 (1436187489272332288)]} 0 6
[junit4:junit4] 2> 48049 T68 C49 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[v!21]} 0 10
[junit4:junit4] 2> 48054 T29 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[w!22 (1436187489284915200)]} 0 2
[junit4:junit4] 2> 48061 T84 C50 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[w!22 (1436187489288060928)]} 0 1
[junit4:junit4] 2> 48063 T52 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[w!22 (1436187489288060928)]} 0 7
[junit4:junit4] 2> 48066 T31 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[x!23 (1436187489297498112)]} 0 1
[junit4:junit4] 2> 48073 T100 C48 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[x!23 (1436187489300643840)]} 0 1
[junit4:junit4] 2> 48077 T66 C49 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[x!23 (1436187489300643840)]} 0 9
[junit4:junit4] 2> 48085 T32 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[y!24 (1436187489316372480)]} 0 1
[junit4:junit4] 2> 48094 T99 C48 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[y!24 (1436187489322663936)]} 0 0
[junit4:junit4] 2> 48096 T69 C49 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[y!24 (1436187489322663936)]} 0 6
[junit4:junit4] 2> 48102 T33 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[z!25 (1436187489335246848)]} 0 0
[junit4:junit4] 2> 48111 T85 C50 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[z!25 (1436187489341538304)]} 0 1
[junit4:junit4] 2> 48112 T53 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[z!25 (1436187489341538304)]} 0 4
[junit4:junit4] 2> 48117 T34 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[a!26 (1436187489349926912)]} 0 2
[junit4:junit4] 2> 48125 T103 C48 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[a!26 (1436187489356218368)]} 0 0
[junit4:junit4] 2> 48126 T70 C49 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[a!26 (1436187489356218368)]} 0 5
[junit4:junit4] 2> 48131 T30 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[b!27 (1436187489365655552)]} 0 1
[junit4:junit4] 2> 48140 T86 C50 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[b!27 (1436187489369849856)]} 0 1
[junit4:junit4] 2> 48141 T54 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[b!27 (1436187489369849856)]} 0 7
[junit4:junit4] 2> 48144 T29 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[c!28 (1436187489378238464)]} 0 1
[junit4:junit4] 2> 48154 T82 C50 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[c!28 (1436187489385578496)]} 0 0
[junit4:junit4] 2> 48156 T49 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[c!28 (1436187489385578496)]} 0 6
[junit4:junit4] 2> 48157 T65 C49 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[c!28]} 0 10
[junit4:junit4] 2> 48160 T31 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[d!29 (1436187489396064256)]} 0 0
[junit4:junit4] 2> 48167 T101 C48 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[d!29 (1436187489399209984)]} 0 1
[junit4:junit4] 2> 48168 T67 C49 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[d!29 (1436187489399209984)]} 0 5
[junit4:junit4] 2> 48184 T32 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[e!30 (1436187489420181504)]} 0 1
[junit4:junit4] 2> 48193 T97 C48 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[e!30 (1436187489424375808)]} 0 2
[junit4:junit4] 2> 48194 T68 C49 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[e!30 (1436187489424375808)]} 0 7
[junit4:junit4] 2> 48197 T33 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[f!31 (1436187489433812992)]} 0 1
[junit4:junit4] 2> 48206 T104 C48 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[f!31 (1436187489441153024)]} 0 0
[junit4:junit4] 2> 48207 T69 C49 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[f!31 (1436187489441153024)]} 0 4
[junit4:junit4] 2> 48208 T50 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[f!31]} 0 9
[junit4:junit4] 2> 48212 T34 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[g!32 (1436187489450590208)]} 0 1
[junit4:junit4] 2> 48221 T81 C50 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[g!32 (1436187489455833088)]} 0 1
[junit4:junit4] 2> 48222 T52 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[g!32 (1436187489455833088)]} 0 5
[junit4:junit4] 2> 48223 T70 C49 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[g!32]} 0 9
[junit4:junit4] 2> 48226 T30 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[h!33 (1436187489465270272)]} 0 0
[junit4:junit4] 2> 48235 T84 C50 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[h!33 (1436187489471561728)]} 0 0
[junit4:junit4] 2> 48236 T53 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[h!33 (1436187489471561728)]} 0 4
[junit4:junit4] 2> 48238 T65 C49 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[h!33]} 0 9
[junit4:junit4] 2> 48242 T31 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[i!34 (1436187489482047488)]} 0 1
[junit4:junit4] 2> 48250 T85 C50 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[i!34 (1436187489486241792)]} 0 1
[junit4:junit4] 2> 48252 T54 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[i!34 (1436187489486241792)]} 0 6
[junit4:junit4] 2> 48254 T32 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[j!35 (1436187489494630400)]} 0 1
[junit4:junit4] 2> 48263 T86 C50 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[j!35 (1436187489500921856)]} 0 1
[junit4:junit4] 2> 48264 T49 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[j!35 (1436187489500921856)]} 0 5
[junit4:junit4] 2> 48265 T67 C49 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[j!35]} 0 8
[junit4:junit4] 2> 48268 T33 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[k!36 (1436187489509310464)]} 0 0
[junit4:junit4] 2> 48275 T82 C50 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[k!36 (1436187489512456192)]} 0 1
[junit4:junit4] 2> 48276 T51 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[k!36 (1436187489512456192)]} 0 5
[junit4:junit4] 2> 48279 T34 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[l!37 (1436187489520844800)]} 0 1
[junit4:junit4] 2> 48288 T102 C48 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[l!37 (1436187489527136256)]} 0 1
[junit4:junit4] 2> 48290 T68 C49 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[l!37 (1436187489527136256)]} 0 6
[junit4:junit4] 2> 48294 T50 C46 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[l!37]} 0 12
[junit4:junit4] 2> 48298 T29 C47 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[m!38 (1436187489540767744)]} 0 1
[junit4:junit4] 2> ASYNC NEW_CORE C51 name=collection1 org.apache.solr.core.SolrCore@27db5a86 url=http://127.0.0.1:63737/collection1 node=127.0.0.1:63737_ C51_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:63737_, base_url=http://127.0.0.1:63737}
[junit4:junit4] 2> 48309 T99 C51 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[m!38 (1436187489549156352)]} 0 1
[junit4:junit4] 2> ASYNC NEW_CORE C52 name=collection1 org.apache.solr.core.SolrCore@189e8b21 url=http://127.0.0.1:63719/collection1 node=127.0.0.1:63719_ C52_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:63719_, base_url=http://127.0.0.1:63719, leader=true}
[junit4:junit4] 2> 48310 T66 C52 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[m!38 (1436187489549156352)]} 0 4
[junit4:junit4] 2> ASYNC NEW_CORE C53 name=collection1 org.apache.solr.core.SolrCore@7e1888b2 url=http://127.0.0.1:63698/collection1 node=127.0.0.1:63698_ C53_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:63698_, base_url=http://127.0.0.1:63698, leader=true}
[junit4:junit4] 2> 48315 T30 C53 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[n!39 (1436187489557544960)]} 0 1
[junit4:junit4] 2> ASYNC NEW_CORE C54 name=collection1 org.apache.solr.core.SolrCore@5bc5960f url=http://127.0.0.1:63728/collection1 node=127.0.0.1:63728_ C54_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:63728_, base_url=http://127.0.0.1:63728}
[junit4:junit4] 2> 48324 T83 C54 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[n!39 (1436187489564884992)]} 0 1
[junit4:junit4] 2> ASYNC NEW_CORE C55 name=collection1 org.apache.solr.core.SolrCore@4fb7a0d3 url=http://127.0.0.1:63710/collection1 node=127.0.0.1:63710_ C55_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:63710_, base_url=http://127.0.0.1:63710, leader=true}
[junit4:junit4] 2> 48326 T52 C55 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[n!39 (1436187489564884992)]} 0 6
[junit4:junit4] 2> 48327 T69 C52 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[n!39]} 0 10
[junit4:junit4] 2> 48331 T31 C53 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[o!40 (1436187489574322176)]} 0 1
[junit4:junit4] 2> 48340 T103 C51 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[o!40 (1436187489582710784)]} 0 0
[junit4:junit4] 2> 48342 T70 C52 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[o!40 (1436187489582710784)]} 0 5
[junit4:junit4] 2> 48343 T53 C55 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[o!40]} 0 9
[junit4:junit4] 2> 48346 T32 C53 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[p!41 (1436187489591099392)]} 0 0
[junit4:junit4] 2> 48353 T81 C54 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[p!41 (1436187489595293696)]} 0 0
[junit4:junit4] 2> 48354 T54 C55 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[p!41 (1436187489595293696)]} 0 5
[junit4:junit4] 2> 48358 T33 C53 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[q!42 (1436187489603682304)]} 0 0
[junit4:junit4] 2> 48369 T84 C54 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[q!42 (1436187489609973760)]} 0 1
[junit4:junit4] 2> 48371 T49 C55 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[q!42 (1436187489609973760)]} 0 7
[junit4:junit4] 2> 48373 T65 C52 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[q!42]} 0 11
[junit4:junit4] 2> 48376 T34 C53 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[r!43 (1436187489622556672)]} 0 0
[junit4:junit4] 2> 48385 T101 C51 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[r!43 (1436187489627799552)]} 0 1
[junit4:junit4] 2> 48399 T67 C52 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[r!43 (1436187489627799552)]} 0 19
[junit4:junit4] 2> 48403 T29 C53 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[s!44 (1436187489650868224)]} 0 0
[junit4:junit4] 2> 48410 T85 C54 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[s!44 (1436187489655062528)]} 0 1
[junit4:junit4] 2> 48411 T51 C55 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[s!44 (1436187489655062528)]} 0 4
[junit4:junit4] 2> 48416 T30 C53 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[t!45 (1436187489663451136)]} 0 1
[junit4:junit4] 2> 48421 T86 C54 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[t!45 (1436187489667645440)]} 0 0
[junit4:junit4] 2> 48423 T50 C55 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[t!45 (1436187489667645440)]} 0 5
[junit4:junit4] 2> 48428 T31 C53 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[u!46 (1436187489676034048)]} 0 1
[junit4:junit4] 2> 48438 T97 C51 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[u!46 (1436187489683374080)]} 0 0
[junit4:junit4] 2> 48440 T68 C52 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[u!46 (1436187489683374080)]} 0 7
[junit4:junit4] 2> 48442 T52 C55 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[u!46]} 0 12
[junit4:junit4] 2> 48448 T32 C53 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[v!47 (1436187489698054144)]} 0 2
[junit4:junit4] 2> 48453 T82 C54 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[v!47 (1436187489700151296)]} 0 0
[junit4:junit4] 2> 48455 T53 C55 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[v!47 (1436187489700151296)]} 0 5
[junit4:junit4] 2> 48458 T33 C53 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[w!48 (1436187489708539904)]} 0 0
[junit4:junit4] 2> 48469 T83 C54 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[w!48 (1436187489715879936)]} 0 2
[junit4:junit4] 2> 48470 T54 C55 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[w!48 (1436187489715879936)]} 0 6
[junit4:junit4] 2> 48471 T66 C52 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[w!48]} 0 9
[junit4:junit4] 2> 48475 T34 C53 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[x!49 (1436187489726365696)]} 0 0
[junit4:junit4] 2> 48483 T104 C51 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[x!49 (1436187489730560000)]} 0 2
[junit4:junit4] 2> 48485 T69 C52 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[x!49 (1436187489730560000)]} 0 6
[junit4:junit4] 2> 48491 T29 C53 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[y!50 (1436187489742094336)]} 0 2
[junit4:junit4] 2> 48501 T100 C51 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[y!50 (1436187489750482944)]} 0 0
[junit4:junit4] 2> 48503 T70 C52 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[y!50 (1436187489750482944)]} 0 5
[junit4:junit4] 2> 48503 T49 C55 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[y!50]} 0 8
[junit4:junit4] 2> 48507 T30 C53 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[z!51 (1436187489759920128)]} 0 1
[junit4:junit4] 2> 48513 T81 C54 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[z!51 (1436187489763065856)]} 0 1
[junit4:junit4] 2> 48514 T51 C55 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[z!51 (1436187489763065856)]} 0 4
[junit4:junit4] 2> 48518 T31 C53 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[a!52 (1436187489770405888)]} 0 1
[junit4:junit4] 2> 48528 T102 C51 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[a!52 (1436187489777745920)]} 0 1
[junit4:junit4] 2> 48530 T65 C52 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[a!52 (1436187489777745920)]} 0 7
[junit4:junit4] 2> 48530 T50 C55 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[a!52]} 0 9
[junit4:junit4] 2> 48534 T32 C53 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[b!53 (1436187489788231680)]} 0 0
[junit4:junit4] 2> 48542 T84 C54 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[b!53 (1436187489793474560)]} 0 1
[junit4:junit4] 2> 48543 T52 C55 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[b!53 (1436187489793474560)]} 0 4
[junit4:junit4] 2> 48547 T33 C53 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[c!54 (1436187489801863168)]} 0 0
[junit4:junit4] 2> 48557 T85 C54 P63728 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[c!54 (1436187489808154624)]} 0 1
[junit4:junit4] 2> 48558 T53 C55 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[c!54 (1436187489808154624)]} 0 6
[junit4:junit4] 2> 48560 T67 C52 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[c!54]} 0 9
[junit4:junit4] 2> 48563 T34 C53 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[d!55 (1436187489818640384)]} 0 1
[junit4:junit4] 2> 48573 T99 C51 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[d!55 (1436187489825980416)]} 0 1
[junit4:junit4] 2> 48575 T68 C52 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63710/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[d!55 (1436187489825980416)]} 0 6
[junit4:junit4] 2> 48577 T54 C55 P63710 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[d!55]} 0 10
[junit4:junit4] 2> 48580 T29 C53 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[e!56 (1436187489836466176)]} 0 0
[junit4:junit4] 2> 48588 T103 C51 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[e!56 (1436187489840660480)]} 0 2
[junit4:junit4] 2> 48589 T66 C52 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[e!56 (1436187489840660480)]} 0 5
[junit4:junit4] 2> 48592 T30 C53 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[f!57 (1436187489849049088)]} 0 1
[junit4:junit4] 2> 48598 T101 C51 P63737 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:63719/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[f!57 (1436187489852194816)]} 0 0
[junit4:junit4] 2> 48600 T69 C52 P63719 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[f!57 (1436187489852194816)]} 0 6
[junit4:junit4] 2> 48603 T31 C53 P63698 oasup.LogUpdateProcessor.finish [collection1] webapp= pa
[...truncated too long message...]
5 T3695 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 1079975 T3695 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 1079985 T3695 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 1079985 T3695 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 1079987 T3695 oasc.CachingDirectoryFactory.closeCacheValue looking to close .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369656086810/jetty4\ [CachedDir<<refCount=0;path=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369656086810/jetty4\;done=false>>]
[junit4:junit4] 2> 1079987 T3695 oasc.CachingDirectoryFactory.close Closing directory: .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369656086810/jetty4\
[junit4:junit4] 2> 1079987 T3695 oasc.CachingDirectoryFactory.closeCacheValue looking to close .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369656086810/jetty4\index [CachedDir<<refCount=0;path=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369656086810/jetty4\index;done=false>>]
[junit4:junit4] 2> 1079989 T3695 oasc.CachingDirectoryFactory.close Closing directory: .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369656086810/jetty4\index
[junit4:junit4] 2> 1079994 T3848 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89761781305638924-127.0.0.1:65332_-n_0000000004) am no longer a leader.
[junit4:junit4] 2> 1079999 T3786 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> 1080017 T3695 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369656086810\zookeeper\server1\data\version-2\log.1 FAILED !!!!!
[junit4:junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369656086810\zookeeper\server1\data\version-2 FAILED !!!!!
[junit4:junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369656086810\zookeeper\server1\data FAILED !!!!!
[junit4:junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369656086810\zookeeper\server1 FAILED !!!!!
[junit4:junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369656086810\zookeeper FAILED !!!!!
[junit4:junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369656086810 FAILED !!!!!
[junit4:junit4] 2> 1080149 T3695 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 1080153 T3695 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:65285 65285
[junit4:junit4] 2> 1081783 T3786 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 1083238 T3786 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 1083242 T3695 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 65292
[junit4:junit4] 2> 1083271 T3695 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 1083271 T3695 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:65285 65285
[junit4:junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeyShardSplitTest -Dtests.method=testDistribSearch -Dtests.seed=B9E7227F21A1A772 -Dtests.slow=true -Dtests.locale=sr_BA_#Latn -Dtests.timezone=Asia/Singapore -Dtests.file.encoding=UTF-8
[junit4:junit4] ERROR 70.5s | ChaosMonkeyShardSplitTest.testDistribSearch <<<
[junit4:junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:65304 returned non ok status:500, message:Server Error
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([B9E7227F21A1A772:3801AC6756FEC74E]:0)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4:junit4] > at org.apache.solr.cloud.ShardSplitTest.splitShard(ShardSplitTest.java:208)
[junit4:junit4] > at org.apache.solr.cloud.ChaosMonkeyShardSplitTest.doTest(ChaosMonkeyShardSplitTest.java:136)
[junit4:junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2> 1083286 T3695 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> NOTE: test params are: codec=Lucene41, sim=DefaultSimilarity, locale=sr_BA_#Latn, timezone=Asia/Singapore
[junit4:junit4] 2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.7.0_21 (64-bit)/cpus=2,threads=3,free=74926120,total=133783552
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestFoldingMultitermQuery, ShardSplitTest, TestValueSourceCache, TestNumberUtils, SearchHandlerTest, TestXIncludeConfig, IndexReaderFactoryTest, TestRTGBase, TestSuggestSpellingConverter, DistributedTermsComponentTest, HardAutoCommitTest, TestSerializedLuceneMatchVersion, TestCodecSupport, DebugComponentTest, CoreContainerCoreInitFailuresTest, TestPostingsSolrHighlighter, MBeansHandlerTest, TestManagedSchema, TestIndexingPerformance, SolrCoreCheckLockOnStartupTest, SolrCmdDistributorTest, TestStressVersions, LeaderElectionIntegrationTest, TestSchemaResource, TestSolrDeletionPolicy1, TestWordDelimiterFilterFactory, JsonLoaderTest, TestQuerySenderListener, TestCloudManagedSchema, TestSolrIndexConfig, SolrInfoMBeanTest, DocValuesTest, CopyFieldTest, OverseerCollectionProcessorTest, ChaosMonkeySafeLeaderTest, OutputWriterTest, TestTrie, StatelessScriptUpdateProcessorFactoryTest, OpenCloseCoreStressTest, ZkNodePropsTest, TestZkChroot, LukeRequestHandlerTest, TestRandomFaceting, DirectSolrSpellCheckerTest, TestUpdate, RAMDirectoryFactoryTest, SolrTestCaseJ4Test, TestReplicationHandler, WordBreakSolrSpellCheckerTest, TestSort, TimeZoneUtilsTest, TestSolr4Spatial, TestCoreContainer, PreAnalyzedUpdateProcessorTest, SliceStateTest, TestReload, NoCacheHeaderTest, TestMaxScoreQueryParser, TestStressReorder, TestJoin, BadComponentTest, PrimUtilsTest, SimplePostToolTest, LegacyHTMLStripCharFilterTest, RequiredFieldsTest, TestDistributedSearch, TestBadConfig, URLClassifyProcessorTest, ResponseLogComponentTest, IndexBasedSpellCheckerTest, TestSolrQueryParserDefaultOperatorResource, AlternateDirectoryTest, TestFieldTypeResource, ExternalFileFieldSortTest, TestSystemIdResolver, AutoCommitTest, SolrCoreTest, TestIndexSearcher, XsltUpdateRequestHandlerTest, BadIndexSchemaTest, TestStressLucene, TestRemoteStreaming, TestDistributedGrouping, SchemaVersionSpecificBehaviorTest, SynonymTokenizerTest, TermVectorComponentDistributedTest, ScriptEngineTest, DirectUpdateHandlerTest, TestSolrQueryParserResource, PeerSyncTest, TestRealTimeGet, TestSolrJ, SliceStateUpdateTest, DirectSolrConnectionTest, TestFieldTypeCollectionResource, UniqFieldsUpdateProcessorFactoryTest, TestIBSimilarityFactory, MultiTermTest, TestClassNameShortening, DisMaxRequestHandlerTest, TermVectorComponentTest, SuggesterTSTTest, CircularListTest, TestCharFilters, FileBasedSpellCheckerTest, PluginInfoTest, PingRequestHandlerTest, JSONWriterTest, NumericFieldsTest, TestCollationField, SpatialFilterTest, IndexSchemaRuntimeFieldTest, DistributedQueryElevationComponentTest, TestPhraseSuggestions, SignatureUpdateProcessorFactoryTest, TestDynamicFieldCollectionResource, QueryParsingTest, PreAnalyzedFieldTest, ShardRoutingTest, AnalysisAfterCoreReloadTest, DateMathParserTest, TestBM25SimilarityFactory, ZkSolrClientTest, ChaosMonkeyShardSplitTest]
[junit4:junit4] Completed in 70.54s, 1 test, 1 error <<< FAILURES!
[...truncated 525 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:380: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:360: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:181: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:437: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1240: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:884: There were test failures: 295 suites, 1231 tests, 1 error, 1 failure, 18 ignored (12 assumptions)
Total time: 64 minutes 55 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_21 -XX:+UseCompressedOops -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure