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/26 19:54:28 UTC
[JENKINS] Lucene-Solr-trunk-Windows (32bit/jdk1.7.0_21) - Build #
2864 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/2864/
Java: 32bit/jdk1.7.0_21 -server -XX:+UseConcMarkSweepGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeyShardSplitTest.testDistribSearch
Error Message:
Server at http://127.0.0.1:57581 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:57581 returned non ok status:500, message:Server Error
at __randomizedtesting.SeedInfo.seed([AC2F33F04745B64B:2DC9BDE8301AD677]: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.GeneratedMethodAccessor42.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:601)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:722)
Build Log:
[...truncated 10002 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.ChaosMonkeyShardSplitTest
[junit4:junit4] 2> 2269412 T6910 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4] 2> 2269416 T6910 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-ChaosMonkeyShardSplitTest-1369590691133
[junit4:junit4] 2> 2269421 T6910 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 2269422 T6911 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 2269521 T6910 oasc.ZkTestServer.run start zk server on port:57562
[junit4:junit4] 2> 2269524 T6910 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2269545 T6917 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@87580d name:ZooKeeperConnection Watcher:127.0.0.1:57562 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2269546 T6910 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2269546 T6910 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 2269560 T6912 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13ee1f775470000, 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> 2269564 T6910 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2269570 T6919 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@197e078 name:ZooKeeperConnection Watcher:127.0.0.1:57562/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2269571 T6910 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2269572 T6910 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 2269587 T6910 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 2269596 T6910 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 2269606 T6910 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 2269616 T6910 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> 2269618 T6910 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 2269635 T6910 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> 2269637 T6910 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 2269648 T6910 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> 2269650 T6910 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 2269660 T6910 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> 2269662 T6910 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 2269672 T6910 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> 2269674 T6910 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 2269683 T6910 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> 2269684 T6910 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 2269695 T6910 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> 2269697 T6910 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 2269707 T6910 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> 2269709 T6910 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 2269719 T6910 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> 2269721 T6910 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 2269736 T6912 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13ee1f775470001, 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> 2270139 T6910 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2270146 T6910 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57569
[junit4:junit4] 2> 2270146 T6910 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2270147 T6910 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2270148 T6910 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.ChaosMonkeyShardSplitTest-controljetty-1369590691449
[junit4:junit4] 2> 2270148 T6910 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.ChaosMonkeyShardSplitTest-controljetty-1369590691449\solr.xml
[junit4:junit4] 2> 2270148 T6910 oasc.CoreContainer.<init> New CoreContainer 31544127
[junit4:junit4] 2> 2270148 T6910 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.ChaosMonkeyShardSplitTest-controljetty-1369590691449\'
[junit4:junit4] 2> 2270148 T6910 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.ChaosMonkeyShardSplitTest-controljetty-1369590691449\'
[junit4:junit4] 2> 2270245 T6910 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 2270245 T6910 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2270246 T6910 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 2270246 T6910 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2270246 T6910 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2270246 T6910 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2270247 T6910 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2270247 T6910 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2270248 T6910 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2270249 T6910 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 2270257 T6910 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2270258 T6910 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57562/solr
[junit4:junit4] 2> 2270258 T6910 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2270260 T6910 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2270277 T6930 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a17397 name:ZooKeeperConnection Watcher:127.0.0.1:57562 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2270277 T6910 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2270280 T6910 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2270287 T6910 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2270292 T6932 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@e113c1 name:ZooKeeperConnection Watcher:127.0.0.1:57562/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2270292 T6910 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2270295 T6910 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 2270303 T6910 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 2270307 T6910 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 2270311 T6910 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57569_
[junit4:junit4] 2> 2270313 T6910 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57569_
[junit4:junit4] 2> 2270318 T6910 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 2270328 T6910 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 2270332 T6910 oasc.Overseer.start Overseer (id=89757495534747651-127.0.0.1:57569_-n_0000000000) starting
[junit4:junit4] 2> 2270340 T6910 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 2270351 T6934 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 2270352 T6910 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 2270358 T6910 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 2270363 T6910 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2270371 T6933 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 2270372 T6935 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.ChaosMonkeyShardSplitTest-controljetty-1369590691449\collection1
[junit4:junit4] 2> 2270372 T6935 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 2270373 T6935 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2270373 T6935 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 2270375 T6935 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.ChaosMonkeyShardSplitTest-controljetty-1369590691449\collection1\'
[junit4:junit4] 2> 2270377 T6935 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1369590691449/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 2270378 T6935 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1369590691449/collection1/lib/README' to classloader
[junit4:junit4] 2> 2270442 T6935 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2270500 T6935 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2270503 T6935 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2270512 T6935 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 2271042 T6935 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2271045 T6935 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2271047 T6935 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2271053 T6935 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2271085 T6935 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2271085 T6935 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.ChaosMonkeyShardSplitTest-controljetty-1369590691449\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/control/data\
[junit4:junit4] 2> 2271085 T6935 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@438ef4
[junit4:junit4] 2> 2271085 T6935 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2271086 T6935 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/control/data\
[junit4:junit4] 2> 2271086 T6935 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/control/data\index/
[junit4:junit4] 2> 2271086 T6935 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131\control\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2271087 T6935 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/control/data\index
[junit4:junit4] 2> 2271091 T6935 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5735d5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1646296),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2271092 T6935 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2271095 T6935 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2271095 T6935 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2271096 T6935 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2271096 T6935 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2271097 T6935 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2271097 T6935 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2271097 T6935 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2271098 T6935 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2271098 T6935 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2271111 T6935 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2271117 T6935 oass.SolrIndexSearcher.<init> Opening Searcher@7acfd7 main
[junit4:junit4] 2> 2271118 T6935 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131\control\data\tlog
[junit4:junit4] 2> 2271119 T6935 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2271120 T6935 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2271124 T6935 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 2271124 T6935 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2271125 T6936 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7acfd7 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2271905 T6933 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2271908 T6933 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:57569_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:57569"}
[junit4:junit4] 2> 2271909 T6933 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 2271909 T6933 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 2271928 T6932 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> 2272195 T6935 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2272195 T6935 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57569 collection:control_collection shard:shard1
[junit4:junit4] 2> 2272198 T6935 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 2272232 T6935 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2272245 T6935 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2272245 T6935 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2272247 T6935 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57569/collection1/
[junit4:junit4] 2> 2272247 T6935 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 2272248 T6935 oasc.SyncStrategy.syncToMe http://127.0.0.1:57569/collection1/ has no replicas
[junit4:junit4] 2> 2272248 T6935 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57569/collection1/
[junit4:junit4] 2> 2272249 T6935 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 2273559 T6933 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2273597 T6932 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> 2273655 T6935 oasc.ZkController.register We are http://127.0.0.1:57569/collection1/ and leader is http://127.0.0.1:57569/collection1/
[junit4:junit4] 2> 2273655 T6935 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57569
[junit4:junit4] 2> 2273655 T6935 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 2273656 T6935 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 2273656 T6935 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2273663 T6935 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2273667 T6910 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 2273668 T6910 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2273669 T6910 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2273689 T6910 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 2273695 T6910 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2273700 T6939 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15ce85b name:ZooKeeperConnection Watcher:127.0.0.1:57562/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2273700 T6910 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2273703 T6910 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2273706 T6910 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 2274178 T6910 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2274184 T6910 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57581
[junit4:junit4] 2> 2274184 T6910 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2274185 T6910 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2274185 T6910 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.ChaosMonkeyShardSplitTest-jetty1-1369590695420
[junit4:junit4] 2> 2274185 T6910 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.ChaosMonkeyShardSplitTest-jetty1-1369590695420\solr.xml
[junit4:junit4] 2> 2274185 T6910 oasc.CoreContainer.<init> New CoreContainer 26875612
[junit4:junit4] 2> 2274186 T6910 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.ChaosMonkeyShardSplitTest-jetty1-1369590695420\'
[junit4:junit4] 2> 2274187 T6910 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.ChaosMonkeyShardSplitTest-jetty1-1369590695420\'
[junit4:junit4] 2> 2274293 T6910 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 2274293 T6910 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2274294 T6910 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 2274294 T6910 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2274295 T6910 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2274295 T6910 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2274296 T6910 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2274296 T6910 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2274296 T6910 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2274297 T6910 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 2274305 T6910 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2274305 T6910 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57562/solr
[junit4:junit4] 2> 2274306 T6910 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2274308 T6910 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2274325 T6950 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9b51ff name:ZooKeeperConnection Watcher:127.0.0.1:57562 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2274325 T6910 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2274329 T6910 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2274329 T6912 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13ee1f775470005, 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> 2274336 T6910 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2274342 T6952 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@98f483 name:ZooKeeperConnection Watcher:127.0.0.1:57562/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2274342 T6910 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2274358 T6910 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2275238 T6933 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2275240 T6933 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:57569__collection1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:57569_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:57569"}
[junit4:junit4] 2> 2275258 T6952 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> 2275259 T6932 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> 2275258 T6939 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> 2275447 T6910 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57581_
[junit4:junit4] 2> 2275453 T6910 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57581_
[junit4:junit4] 2> 2275465 T6952 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> 2275467 T6939 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 2275468 T6939 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> 2275471 T6932 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 2275472 T6932 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> 2275481 T6952 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 2275494 T6953 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.ChaosMonkeyShardSplitTest-jetty1-1369590695420\collection1
[junit4:junit4] 2> 2275494 T6953 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 2275497 T6953 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2275497 T6953 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 2275500 T6953 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.ChaosMonkeyShardSplitTest-jetty1-1369590695420\collection1\'
[junit4:junit4] 2> 2275504 T6953 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1369590695420/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 2275506 T6953 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1369590695420/collection1/lib/README' to classloader
[junit4:junit4] 2> 2275560 T6953 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2275624 T6953 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2275626 T6953 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2275634 T6953 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 2276222 T6953 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2276226 T6953 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2276227 T6953 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2276235 T6953 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2276269 T6953 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2276270 T6953 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.ChaosMonkeyShardSplitTest-jetty1-1369590695420\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/jetty1\
[junit4:junit4] 2> 2276270 T6953 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@438ef4
[junit4:junit4] 2> 2276270 T6953 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2276271 T6953 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/jetty1\
[junit4:junit4] 2> 2276271 T6953 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/jetty1\index/
[junit4:junit4] 2> 2276271 T6953 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131\jetty1\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2276272 T6953 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/jetty1\index
[junit4:junit4] 2> 2276277 T6953 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1246f19 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16b1cf5),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2276277 T6953 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2276281 T6953 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2276281 T6953 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2276282 T6953 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2276282 T6953 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2276283 T6953 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2276283 T6953 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2276283 T6953 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2276284 T6953 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2276284 T6953 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2276297 T6953 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2276304 T6953 oass.SolrIndexSearcher.<init> Opening Searcher@1734142 main
[junit4:junit4] 2> 2276304 T6953 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131\jetty1\tlog
[junit4:junit4] 2> 2276306 T6953 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2276306 T6953 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2276311 T6954 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1734142 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2276312 T6953 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 2276314 T6953 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2276895 T6933 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2276897 T6933 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:57581_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:57581"}
[junit4:junit4] 2> 2276897 T6933 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 2276898 T6933 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 2276916 T6952 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> 2276916 T6939 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> 2276917 T6932 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> 2277397 T6953 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2277397 T6953 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57581 collection:collection1 shard:shard1
[junit4:junit4] 2> 2277399 T6953 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 2277432 T6953 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2277443 T6953 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2277444 T6953 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2277444 T6953 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57581/collection1/
[junit4:junit4] 2> 2277445 T6953 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 2277445 T6953 oasc.SyncStrategy.syncToMe http://127.0.0.1:57581/collection1/ has no replicas
[junit4:junit4] 2> 2277446 T6953 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57581/collection1/
[junit4:junit4] 2> 2277446 T6953 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 2278551 T6933 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2278591 T6952 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> 2278591 T6932 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> 2278591 T6939 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> 2278624 T6953 oasc.ZkController.register We are http://127.0.0.1:57581/collection1/ and leader is http://127.0.0.1:57581/collection1/
[junit4:junit4] 2> 2278624 T6953 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57581
[junit4:junit4] 2> 2278625 T6953 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 2278625 T6953 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 2278627 T6953 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2278633 T6953 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2278636 T6910 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 2278637 T6910 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2278638 T6910 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2279095 T6910 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2279126 T6910 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57590
[junit4:junit4] 2> 2279127 T6910 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2279127 T6910 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2279128 T6910 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.ChaosMonkeyShardSplitTest-jetty2-1369590700368
[junit4:junit4] 2> 2279128 T6910 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.ChaosMonkeyShardSplitTest-jetty2-1369590700368\solr.xml
[junit4:junit4] 2> 2279128 T6910 oasc.CoreContainer.<init> New CoreContainer 32479779
[junit4:junit4] 2> 2279128 T6910 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.ChaosMonkeyShardSplitTest-jetty2-1369590700368\'
[junit4:junit4] 2> 2279129 T6910 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.ChaosMonkeyShardSplitTest-jetty2-1369590700368\'
[junit4:junit4] 2> 2279245 T6910 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 2279246 T6910 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2279246 T6910 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 2279247 T6910 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2279248 T6910 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2279248 T6910 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2279249 T6910 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2279250 T6910 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2279251 T6910 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2279252 T6910 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 2279260 T6910 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2279261 T6910 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57562/solr
[junit4:junit4] 2> 2279261 T6910 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2279263 T6910 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2279313 T6966 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c68c47 name:ZooKeeperConnection Watcher:127.0.0.1:57562 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2279313 T6910 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2279317 T6910 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2279318 T6912 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13ee1f775470007, 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> 2279330 T6910 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2279339 T6968 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@a14bf0 name:ZooKeeperConnection Watcher:127.0.0.1:57562/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2279339 T6910 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2279357 T6910 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2280233 T6933 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2280235 T6933 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:57581__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:57581_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:57581"}
[junit4:junit4] 2> 2280254 T6952 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> 2280255 T6932 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> 2280256 T6968 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> 2280254 T6939 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> 2280445 T6910 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57590_
[junit4:junit4] 2> 2280450 T6910 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57590_
[junit4:junit4] 2> 2280458 T6952 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> 2280462 T6932 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2280462 T6932 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> 2280463 T6968 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2280465 T6939 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2280466 T6939 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> 2280465 T6968 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> 2280469 T6952 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2280488 T6969 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.ChaosMonkeyShardSplitTest-jetty2-1369590700368\collection1
[junit4:junit4] 2> 2280488 T6969 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 2280491 T6969 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2280491 T6969 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 2280497 T6969 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.ChaosMonkeyShardSplitTest-jetty2-1369590700368\collection1\'
[junit4:junit4] 2> 2280500 T6969 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1369590700368/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 2280503 T6969 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1369590700368/collection1/lib/README' to classloader
[junit4:junit4] 2> 2280567 T6969 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2280630 T6969 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2280632 T6969 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2280641 T6969 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 2281247 T6969 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2281251 T6969 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2281253 T6969 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2281259 T6969 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2281307 T6969 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2281308 T6969 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.ChaosMonkeyShardSplitTest-jetty2-1369590700368\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/jetty2\
[junit4:junit4] 2> 2281308 T6969 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@438ef4
[junit4:junit4] 2> 2281308 T6969 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2281309 T6969 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/jetty2\
[junit4:junit4] 2> 2281309 T6969 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/jetty2\index/
[junit4:junit4] 2> 2281310 T6969 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131\jetty2\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2281310 T6969 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/jetty2\index
[junit4:junit4] 2> 2281314 T6969 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@a3bf8c lockFactory=org.apache.lucene.store.NativeFSLockFactory@13198b6),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2281315 T6969 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2281319 T6969 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2281319 T6969 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2281320 T6969 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2281320 T6969 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2281321 T6969 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2281321 T6969 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2281321 T6969 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2281322 T6969 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2281322 T6969 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2281332 T6969 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2281340 T6969 oass.SolrIndexSearcher.<init> Opening Searcher@a765ae main
[junit4:junit4] 2> 2281340 T6969 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131\jetty2\tlog
[junit4:junit4] 2> 2281341 T6969 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2281341 T6969 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2281350 T6969 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 2281350 T6969 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2281352 T6970 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@a765ae main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2281888 T6933 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2281889 T6933 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:57590_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:57590"}
[junit4:junit4] 2> 2281889 T6933 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 2281889 T6933 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 2281900 T6952 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> 2281900 T6932 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> 2281901 T6968 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> 2281900 T6939 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> 2282398 T6969 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2282398 T6969 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57590 collection:collection1 shard:shard2
[junit4:junit4] 2> 2282400 T6969 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 2282423 T6969 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2282434 T6969 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2282435 T6969 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2282435 T6969 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:57590/collection1/
[junit4:junit4] 2> 2282436 T6969 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 2282436 T6969 oasc.SyncStrategy.syncToMe http://127.0.0.1:57590/collection1/ has no replicas
[junit4:junit4] 2> 2282437 T6969 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:57590/collection1/
[junit4:junit4] 2> 2282437 T6969 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 2283382 T6933 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2283417 T6952 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> 2283417 T6939 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> 2283417 T6968 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> 2283417 T6932 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> 2283444 T6969 oasc.ZkController.register We are http://127.0.0.1:57590/collection1/ and leader is http://127.0.0.1:57590/collection1/
[junit4:junit4] 2> 2283444 T6969 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57590
[junit4:junit4] 2> 2283444 T6969 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 2283446 T6969 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 2283446 T6969 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2283452 T6969 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2283455 T6910 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 2283455 T6910 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2283456 T6910 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2283842 T6910 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2283846 T6910 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57599
[junit4:junit4] 2> 2283847 T6910 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2283847 T6910 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2283848 T6910 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.ChaosMonkeyShardSplitTest-jetty3-1369590705187
[junit4:junit4] 2> 2283848 T6910 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.ChaosMonkeyShardSplitTest-jetty3-1369590705187\solr.xml
[junit4:junit4] 2> 2283849 T6910 oasc.CoreContainer.<init> New CoreContainer 19539963
[junit4:junit4] 2> 2283849 T6910 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.ChaosMonkeyShardSplitTest-jetty3-1369590705187\'
[junit4:junit4] 2> 2283849 T6910 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.ChaosMonkeyShardSplitTest-jetty3-1369590705187\'
[junit4:junit4] 2> 2283951 T6910 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 2283951 T6910 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2283951 T6910 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 2283952 T6910 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2283952 T6910 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2283952 T6910 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2283953 T6910 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2283953 T6910 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2283954 T6910 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2283954 T6910 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 2283960 T6910 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2283961 T6910 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57562/solr
[junit4:junit4] 2> 2283961 T6910 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2283963 T6910 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2283978 T6982 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11c9a3c name:ZooKeeperConnection Watcher:127.0.0.1:57562 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2283978 T6910 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2283981 T6910 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2283981 T6912 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13ee1f775470009, 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> 2283987 T6910 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2283990 T6984 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1c877bf name:ZooKeeperConnection Watcher:127.0.0.1:57562/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2283990 T6910 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2283997 T6910 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2284898 T6933 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2284900 T6933 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:57590__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:57590_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:57590"}
[junit4:junit4] 2> 2284919 T6952 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> 2284921 T6939 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> 2284921 T6968 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> 2284921 T6932 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> 2284921 T6984 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> 2284973 T6910 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57599_
[junit4:junit4] 2> 2284977 T6910 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57599_
[junit4:junit4] 2> 2284986 T6952 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> 2284987 T6984 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> 2284989 T6939 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2284989 T6939 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> 2284992 T6932 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2284993 T6932 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> 2284993 T6968 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2284995 T6968 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> 2284997 T6952 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2285000 T6984 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2285009 T6985 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.ChaosMonkeyShardSplitTest-jetty3-1369590705187\collection1
[junit4:junit4] 2> 2285009 T6985 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 2285011 T6985 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2285011 T6985 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 2285013 T6985 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.ChaosMonkeyShardSplitTest-jetty3-1369590705187\collection1\'
[junit4:junit4] 2> 2285015 T6985 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1369590705187/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 2285016 T6985 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1369590705187/collection1/lib/README' to classloader
[junit4:junit4] 2> 2285071 T6985 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2285127 T6985 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2285130 T6985 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2285137 T6985 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 2285678 T6985 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2285682 T6985 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2285684 T6985 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2285688 T6985 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2285720 T6985 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2285721 T6985 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.ChaosMonkeyShardSplitTest-jetty3-1369590705187\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/jetty3\
[junit4:junit4] 2> 2285721 T6985 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@438ef4
[junit4:junit4] 2> 2285722 T6985 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2285722 T6985 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/jetty3\
[junit4:junit4] 2> 2285722 T6985 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/jetty3\index/
[junit4:junit4] 2> 2285723 T6985 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131\jetty3\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2285723 T6985 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/jetty3\index
[junit4:junit4] 2> 2285727 T6985 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@c79a0c lockFactory=org.apache.lucene.store.NativeFSLockFactory@5abcf6),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2285727 T6985 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2285731 T6985 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2285731 T6985 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2285732 T6985 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2285732 T6985 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2285732 T6985 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2285732 T6985 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2285734 T6985 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2285735 T6985 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2285735 T6985 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2285747 T6985 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2285753 T6985 oass.SolrIndexSearcher.<init> Opening Searcher@10321db main
[junit4:junit4] 2> 2285753 T6985 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131\jetty3\tlog
[junit4:junit4] 2> 2285755 T6985 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2285755 T6985 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2285761 T6986 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@10321db main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2285762 T6985 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 2285762 T6985 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2286397 T6933 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2286399 T6933 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:57599_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:57599"}
[junit4:junit4] 2> 2286400 T6933 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 2286400 T6933 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 2286420 T6952 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> 2286421 T6932 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> 2286422 T6984 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> 2286422 T6968 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> 2286421 T6939 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> 2286740 T6985 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2286740 T6985 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57599 collection:collection1 shard:shard1
[junit4:junit4] 2> 2286752 T6985 oasc.ZkController.register We are http://127.0.0.1:57599/collection1/ and leader is http://127.0.0.1:57581/collection1/
[junit4:junit4] 2> 2286752 T6985 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57599
[junit4:junit4] 2> 2286753 T6985 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 2286753 T6985 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C6115 name=collection1 org.apache.solr.core.SolrCore@36aae2 url=http://127.0.0.1:57599/collection1 node=127.0.0.1:57599_ C6115_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:57599_, base_url=http://127.0.0.1:57599}
[junit4:junit4] 2> 2286755 T6987 C6115 P57599 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 2286757 T6987 C6115 P57599 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 2286758 T6987 C6115 P57599 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 2286758 T6985 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2286758 T6987 C6115 P57599 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2286763 T6910 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 2286763 T6910 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2286764 T6910 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2286764 T6987 C6115 P57599 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2286787 T6943 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:57599__collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 2287182 T6910 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2287186 T6910 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:57609
[junit4:junit4] 2> 2287187 T6910 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2287187 T6910 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2287187 T6910 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.ChaosMonkeyShardSplitTest-jetty4-1369590708498
[junit4:junit4] 2> 2287188 T6910 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.ChaosMonkeyShardSplitTest-jetty4-1369590708498\solr.xml
[junit4:junit4] 2> 2287188 T6910 oasc.CoreContainer.<init> New CoreContainer 15340174
[junit4:junit4] 2> 2287188 T6910 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.ChaosMonkeyShardSplitTest-jetty4-1369590708498\'
[junit4:junit4] 2> 2287188 T6910 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.ChaosMonkeyShardSplitTest-jetty4-1369590708498\'
[junit4:junit4] 2> 2287284 T6910 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 2287284 T6910 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2287285 T6910 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 2287285 T6910 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2287286 T6910 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2287286 T6910 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2287286 T6910 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2287286 T6910 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2287286 T6910 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2287287 T6910 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 2287293 T6910 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2287294 T6910 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:57562/solr
[junit4:junit4] 2> 2287295 T6910 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2287296 T6910 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2287317 T6999 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@cf40e7 name:ZooKeeperConnection Watcher:127.0.0.1:57562 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2287317 T6910 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2287320 T6910 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2287320 T6912 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13ee1f77547000b, 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> 2287328 T6910 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2287332 T7001 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@96a44 name:ZooKeeperConnection Watcher:127.0.0.1:57562/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2287333 T6910 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2287341 T6910 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2287895 T6933 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2287897 T6933 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:57599__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:57599_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:57599"}
[junit4:junit4] 2> 2287917 T6939 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> 2287917 T6952 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> 2287918 T6932 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> 2287919 T6984 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> 2287919 T6968 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> 2287917 T7001 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> 2288316 T6910 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57609_
[junit4:junit4] 2> 2288320 T6910 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:57609_
[junit4:junit4] 2> 2288330 T7001 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> 2288332 T6952 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> 2288333 T6939 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2288334 T6939 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> 2288332 T6984 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> 2288336 T6932 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2288336 T6932 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> 2288337 T6968 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2288338 T6968 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> 2288341 T7001 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2288344 T6952 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2288344 T6984 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2288351 T7002 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.ChaosMonkeyShardSplitTest-jetty4-1369590708498\collection1
[junit4:junit4] 2> 2288351 T7002 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 2288352 T7002 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2288352 T7002 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 2288354 T7002 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.ChaosMonkeyShardSplitTest-jetty4-1369590708498\collection1\'
[junit4:junit4] 2> 2288355 T7002 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1369590708498/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 2288356 T7002 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1369590708498/collection1/lib/README' to classloader
[junit4:junit4] 2> 2288402 T7002 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2288458 T7002 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2288460 T7002 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2288467 T7002 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 2288729 T6943 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:57599__collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 2288730 T6943 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:57599__collection1&state=recovering&nodeName=127.0.0.1:57599_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1943
[junit4:junit4] 2> 2289002 T7002 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2289005 T7002 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2289006 T7002 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2289013 T7002 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2289051 T7002 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2289052 T7002 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.ChaosMonkeyShardSplitTest-jetty4-1369590708498\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/jetty4\
[junit4:junit4] 2> 2289052 T7002 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@438ef4
[junit4:junit4] 2> 2289053 T7002 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2289053 T7002 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/jetty4\
[junit4:junit4] 2> 2289053 T7002 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/jetty4\index/
[junit4:junit4] 2> 2289054 T7002 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131\jetty4\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2289054 T7002 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/jetty4\index
[junit4:junit4] 2> 2289058 T7002 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8adbf7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@45d186),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2289058 T7002 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2289062 T7002 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2289062 T7002 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2289063 T7002 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2289064 T7002 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2289064 T7002 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2289064 T7002 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2289064 T7002 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2289066 T7002 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2289066 T7002 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2289078 T7002 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2289086 T7002 oass.SolrIndexSearcher.<init> Opening Searcher@f0eb16 main
[junit4:junit4] 2> 2289086 T7002 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131\jetty4\tlog
[junit4:junit4] 2> 2289087 T7002 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2289087 T7002 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2289093 T7003 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f0eb16 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2289094 T7002 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 2289094 T7002 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2289394 T6933 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2289396 T6933 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:57609_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:57609"}
[junit4:junit4] 2> 2289396 T6933 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 2289397 T6933 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 2289417 T6952 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> 2289417 T7001 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> 2289417 T6939 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> 2289417 T6968 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> 2289417 T6984 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> 2289417 T6932 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> 2290069 T7002 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2290069 T7002 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:57609 collection:collection1 shard:shard2
[junit4:junit4] 2> 2290101 T7002 oasc.ZkController.register We are http://127.0.0.1:57609/collection1/ and leader is http://127.0.0.1:57590/collection1/
[junit4:junit4] 2> 2290101 T7002 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:57609
[junit4:junit4] 2> 2290101 T7002 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 2290101 T7002 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C6116 name=collection1 org.apache.solr.core.SolrCore@1004b6f url=http://127.0.0.1:57609/collection1 node=127.0.0.1:57609_ C6116_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:57609_, base_url=http://127.0.0.1:57609}
[junit4:junit4] 2> 2290102 T7004 C6116 P57609 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 2290103 T7004 C6116 P57609 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 2290104 T7004 C6116 P57609 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 2290104 T7004 C6116 P57609 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2290104 T7002 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2290108 T7004 C6116 P57609 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2290109 T6910 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 2290109 T6910 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2290109 T6910 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2290116 T6910 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2290117 T6910 oasc.AbstractFullDistribZkTestBase.waitForThingsToLevelOut Wait for recoveries to finish - wait 15 for each attempt
[junit4:junit4] 2> 2290117 T6910 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):15
[junit4:junit4] 2> 2290118 T6964 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:57609__collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 2290118 T6910 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> ASYNC NEW_CORE C6117 name=collection1 org.apache.solr.core.SolrCore@36aae2 url=http://127.0.0.1:57599/collection1 node=127.0.0.1:57599_ C6117_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:57599_, base_url=http://127.0.0.1:57599}
[junit4:junit4] 2> 2290670 T6987 C6117 P57599 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:57581/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 2290670 T6987 C6117 P57599 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:57599 START replicas=[http://127.0.0.1:57581/collection1/] nUpdates=100
[junit4:junit4] 2> 2290672 T6987 C6117 P57599 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 2290672 T6987 C6117 P57599 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 2290672 T6987 C6117 P57599 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 2290674 T6987 C6117 P57599 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 2290675 T6987 C6117 P57599 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 2290675 T6987 C6117 P57599 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:57581/collection1/. core=collection1
[junit4:junit4] 2> 2290676 T6987 C6117 P57599 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C6118 name=collection1 org.apache.solr.core.SolrCore@fe0f40 url=http://127.0.0.1:57581/collection1 node=127.0.0.1:57581_ C6118_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:57581_, base_url=http://127.0.0.1:57581, leader=true}
[junit4:junit4] 2> 2290691 T6944 C6118 P57581 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=2
[junit4:junit4] 2> 2290697 T6945 C6118 P57581 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2290700 T6945 C6118 P57581 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1246f19 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16b1cf5),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2290700 T6945 C6118 P57581 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2290702 T6945 C6118 P57581 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1246f19 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16b1cf5),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1246f19 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16b1cf5),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2290702 T6945 C6118 P57581 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2290702 T6945 C6118 P57581 oass.SolrIndexSearcher.<init> Opening Searcher@1881be3 realtime
[junit4:junit4] 2> 2290702 T6945 C6118 P57581 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2290702 T6945 C6118 P57581 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 5
[junit4:junit4] 2> 2290704 T6987 C6117 P57599 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2290704 T6987 C6117 P57599 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 2290706 T6947 C6118 P57581 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2290707 T6947 C6118 P57581 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=2
[junit4:junit4] 2> 2290708 T6987 C6117 P57599 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 2290708 T6987 C6117 P57599 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 2290708 T6987 C6117 P57599 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 2290710 T6948 C6118 P57581 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=0
[junit4:junit4] 2> 2290711 T6987 C6117 P57599 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 2290712 T6987 C6117 P57599 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/jetty3\index.20130526175152425
[junit4:junit4] 2> 2290712 T6987 C6117 P57599 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@3cf8c3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16e2ce) fullCopy=false
[junit4:junit4] 2> ASYNC NEW_CORE C6119 name=collection1 org.apache.solr.core.SolrCore@fe0f40 url=http://127.0.0.1:57581/collection1 node=127.0.0.1:57581_ C6119_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:57581_, base_url=http://127.0.0.1:57581, leader=true}
[junit4:junit4] 2> 2290725 T6944 C6119 P57581 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> ASYNC NEW_CORE C6120 name=collection1 org.apache.solr.core.SolrCore@36aae2 url=http://127.0.0.1:57599/collection1 node=127.0.0.1:57599_ C6120_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:57599_, base_url=http://127.0.0.1:57599}
[junit4:junit4] 2> 2290727 T6987 C6120 P57599 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 2290728 T6987 C6120 P57599 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 2290728 T6987 C6120 P57599 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 2290731 T6987 C6120 P57599 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@c79a0c lockFactory=org.apache.lucene.store.NativeFSLockFactory@5abcf6),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@c79a0c lockFactory=org.apache.lucene.store.NativeFSLockFactory@5abcf6),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2290731 T6987 C6120 P57599 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2290732 T6987 C6120 P57599 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 2290732 T6987 C6120 P57599 oass.SolrIndexSearcher.<init> Opening Searcher@1edf24 main
[junit4:junit4] 2> 2290733 T6986 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1edf24 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2290733 T6987 C6120 P57599 oasc.CachingDirectoryFactory.closeCacheValue looking to close .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/jetty3\index.20130526175152425 [CachedDir<<refCount=0;path=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/jetty3\index.20130526175152425;done=true>>]
[junit4:junit4] 2> 2290733 T6987 C6120 P57599 oasc.CachingDirectoryFactory.close Closing directory: .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/jetty3\index.20130526175152425
[junit4:junit4] 2> 2290733 T6987 C6120 P57599 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/jetty3\index.20130526175152425
[junit4:junit4] 2> 2290733 T6987 C6120 P57599 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 2290733 T6987 C6120 P57599 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 2290734 T6987 C6120 P57599 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 2290734 T6987 C6120 P57599 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2290738 T6987 C6120 P57599 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 2290891 T6933 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2290892 T6933 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:57609__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:57609_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:57609"}
[junit4:junit4] 2> 2290899 T6933 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:57599__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:57599_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:57599"}
[junit4:junit4] 2> 2290907 T6952 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> 2290908 T7001 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> 2290908 T6968 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> 2290907 T6939 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> 2290908 T6984 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> 2290908 T6932 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> 2291088 T6964 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:57609__collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 2291088 T6964 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:57609__collection1&state=recovering&nodeName=127.0.0.1:57609_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=970
[junit4:junit4] 2> 2291090 T6910 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2292072 T6910 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> ASYNC NEW_CORE C6121 name=collection1 org.apache.solr.core.SolrCore@1004b6f url=http://127.0.0.1:57609/collection1 node=127.0.0.1:57609_ C6121_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:57609_, base_url=http://127.0.0.1:57609}
[junit4:junit4] 2> 2293070 T7004 C6121 P57609 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:57590/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 2293070 T7004 C6121 P57609 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:57609 START replicas=[http://127.0.0.1:57590/collection1/] nUpdates=100
[junit4:junit4] 2> 2293072 T7004 C6121 P57609 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 2293072 T7004 C6121 P57609 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 2293073 T7004 C6121 P57609 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 2293074 T7004 C6121 P57609 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 2293075 T6910 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2293077 T7004 C6121 P57609 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 2293077 T7004 C6121 P57609 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:57590/collection1/. core=collection1
[junit4:junit4] 2> 2293077 T7004 C6121 P57609 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C6122 name=collection1 org.apache.solr.core.SolrCore@1228cc3 url=http://127.0.0.1:57590/collection1 node=127.0.0.1:57590_ C6122_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:57590_, base_url=http://127.0.0.1:57590, leader=true}
[junit4:junit4] 2> 2293090 T6959 C6122 P57590 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 2> 2293097 T6964 C6122 P57590 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2293101 T6964 C6122 P57590 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@a3bf8c lockFactory=org.apache.lucene.store.NativeFSLockFactory@13198b6),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2293101 T6964 C6122 P57590 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2293101 T6964 C6122 P57590 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@a3bf8c lockFactory=org.apache.lucene.store.NativeFSLockFactory@13198b6),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@a3bf8c lockFactory=org.apache.lucene.store.NativeFSLockFactory@13198b6),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2293101 T6964 C6122 P57590 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2293102 T6964 C6122 P57590 oass.SolrIndexSearcher.<init> Opening Searcher@14cff7c realtime
[junit4:junit4] 2> 2293102 T6964 C6122 P57590 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2293103 T6964 C6122 P57590 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 6
[junit4:junit4] 2> 2293104 T7004 C6121 P57609 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2293104 T7004 C6121 P57609 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 2293106 T6962 C6122 P57590 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2293106 T6962 C6122 P57590 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4:junit4] 2> 2293107 T7004 C6121 P57609 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 2293107 T7004 C6121 P57609 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 2293107 T7004 C6121 P57609 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 2293110 T6961 C6122 P57590 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=0
[junit4:junit4] 2> 2293111 T7004 C6121 P57609 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 2293111 T7004 C6121 P57609 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/jetty4\index.20130526175154825
[junit4:junit4] 2> 2293111 T7004 C6121 P57609 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@eab4ea lockFactory=org.apache.lucene.store.NativeFSLockFactory@1c2890d) fullCopy=false
[junit4:junit4] 2> 2293113 T6958 C6122 P57590 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> 2293114 T7004 C6121 P57609 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 2293115 T7004 C6121 P57609 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 2293115 T7004 C6121 P57609 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 2293117 T7004 C6121 P57609 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8adbf7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@45d186),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8adbf7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@45d186),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2293117 T7004 C6121 P57609 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2293118 T7004 C6121 P57609 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 2293118 T7004 C6121 P57609 oass.SolrIndexSearcher.<init> Opening Searcher@f2382b main
[junit4:junit4] 2> 2293119 T7003 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@f2382b main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2293119 T7004 C6121 P57609 oasc.CachingDirectoryFactory.closeCacheValue looking to close .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/jetty4\index.20130526175154825 [CachedDir<<refCount=0;path=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/jetty4\index.20130526175154825;done=true>>]
[junit4:junit4] 2> 2293119 T7004 C6121 P57609 oasc.CachingDirectoryFactory.close Closing directory: .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/jetty4\index.20130526175154825
[junit4:junit4] 2> 2293119 T7004 C6121 P57609 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1369590691131/jetty4\index.20130526175154825
[junit4:junit4] 2> 2293119 T7004 C6121 P57609 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 2293119 T7004 C6121 P57609 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 2293119 T7004 C6121 P57609 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 2293119 T7004 C6121 P57609 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2293125 T7004 C6121 P57609 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 2293900 T6933 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2293902 T6933 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:57609__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:57609_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:57609"}
[junit4:junit4] 2> 2293920 T6939 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> 2293920 T6932 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> 2293921 T6984 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> 2293922 T6968 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> 2293920 T6952 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> 2293921 T7001 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> 2294092 T6910 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2294094 T6910 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: collection1
[junit4:junit4] 2> ASYNC NEW_CORE C6123 name=collection1 org.apache.solr.core.SolrCore@2f6d58 url=http://127.0.0.1:57569/collection1 node=127.0.0.1:57569_ C6123_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:57569_, base_url=http://127.0.0.1:57569, leader=true}
[junit4:junit4] 2> 2294113 T6923 C6123 P57569 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2294121 T6923 C6123 P57569 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5735d5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1646296),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2294122 T6923 C6123 P57569 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2294123 T6923 C6123 P57569 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5735d5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1646296),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5735d5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1646296),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2294124 T6923 C6123 P57569 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2294125 T6923 C6123 P57569 oass.SolrIndexSearcher.<init> Opening Searcher@1f9472b main
[junit4:junit4] 2> 2294126 T6923 C6123 P57569 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2294128 T6936 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1f9472b main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2294129 T6923 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 16
[junit4:junit4] 2> 2294143 T6944 C6119 P57581 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2294144 T6944 C6119 P57581 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1246f19 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16b1cf5),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1246f19 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16b1cf5),segFN=segments_3,generation=3}
[junit4:junit4] 2> 2294145 T6944 C6119 P57581 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 2294148 T6944 C6119 P57581 oass.SolrIndexSearcher.<init> Opening Searcher@5526f2 main
[junit4:junit4] 2> 2294148 T6944 C6119 P57581 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2294150 T6954 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5526f2 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2294151 T6944 C6119 P57581 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:57599/collection1/, StdNode: http://127.0.0.1:57590/collection1/, StdNode: http://127.0.0.1:57609/collection1/] params:commit_end_point=true&commit=true&softCommit=false&waitSearcher=true&expungeDeletes=false
[junit4:junit4] 2> 2294160 T6964 C6122 P57590 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2294161 T6964 C6122 P57590 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@a3bf8c lockFactory=org.apache.lucene.store.NativeFSLockFactory@13198b6),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@a3bf8c lockFactory=org.apache.lucene.store.NativeFSLockFactory@13198b6),segFN=segments_3,generation=3}
[junit4:junit4] 2> 2294161 T6964 C6122 P57590 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 2294163 T6964 C6122 P57590 oass.SolrIndexSearcher.<init> Opening Searcher@10f234f main
[junit4:junit4] 2> 2294163 T6964 C6122 P57590 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2294164 T6970 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@10f234f main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2294167 T6964 C6122 P57590 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 7
[junit4:junit4] 2> C6120_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:57599_, base_url=http://127.0.0.1:57599}
[junit4:junit4] 2> 2294175 T6978 C6120 P57599 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2294178 T6978 C6120 P57599 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@c79a0c lockFactory=org.apache.lucene.store.NativeFSLockFactory@5abcf6),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@c79a0c lockFactory=org.apache.lucene.store.NativeFSLockFactory@5abcf6),segFN=segments_3,generation=3}
[junit4:junit4] 2> 2294179 T6978 C6120 P57599 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 2294179 T6978 C6120 P57599 oass.SolrIndexSearcher.<init> Opening Searcher@6dc2c5 main
[junit4:junit4] 2> 2294181 T6978 C6120 P57599 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2294182 T6986 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6dc2c5 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2294184 T6978 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 9
[junit4:junit4] 2> C6121_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:57609_, base_url=http://127.0.0.1:57609}
[junit4:junit4] 2> 2294185 T6995 C6121 P57609 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2294186 T6995 C6121 P57609 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8adbf7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@45d186),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@8adbf7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@45d186),segFN=segments_3,generation=3}
[junit4:junit4] 2> 2294187 T6995 C6121 P57609 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 2294189 T6995 C6121 P57609 oass.SolrIndexSearcher.<init> Opening Searcher@17580f8 main
[junit4:junit4] 2> 2294190 T6995 C6121 P57609 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2294191 T7003 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@17580f8 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2294192 T6995 C6121 P57609 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 8
[junit4:junit4] 2> 2294193 T6944 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 50
[junit4:junit4] 2> 2294195 T6910 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2294202 T6946 C6119 P57581 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> 2294206 T6979 C6120 P57599 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> 2294210 T6962 C6122 P57590 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> 2294215 T6996 C6121 P57609 oasc.SolrCore.execute [collection1] webapp= path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=2
[junit4:junit4] 2> 2296223 T6928 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1436119956647313408)} 0 4
[junit4:junit4] 2> 2296232 T6995 C6121 P57609 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={update.distrib=FROMLEADER&_version_=-1436119956654653440&update.from=http://127.0.0.1:57590/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1436119956654653440)} 0 1
[junit4:junit4] 2> 2296236 T6977 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={update.distrib=FROMLEADER&_version_=-1436119956659896320&update.from=http://127.0.0.1:57581/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1436119956659896320)} 0 2
[junit4:junit4] 2> 2296236 T6948 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={update.distrib=TOLEADER&wt=javabin&version=2} {deleteByQuery=*:* (-1436119956659896320)} 0 5
[junit4:junit4] 2> 2296238 T6964 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1436119956654653440)} 0 13
[junit4:junit4] 2> 2296240 T6923 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[0 (1436119956669333504)]} 0 0
[junit4:junit4] 2> 2296247 T6978 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[0 (1436119956673527808)]} 0 0
[junit4:junit4] 2> 2296249 T6944 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[0 (1436119956673527808)]} 0 5
[junit4:junit4] 2> 2296249 T6962 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[0]} 0 6
[junit4:junit4] 2> 2296252 T6925 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[1 (1436119956681916416)]} 0 0
[junit4:junit4] 2> 2296259 T6979 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[1 (1436119956687159296)]} 0 0
[junit4:junit4] 2> 2296260 T6946 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[1 (1436119956687159296)]} 0 3
[junit4:junit4] 2> 2296260 T6961 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[1]} 0 5
[junit4:junit4] 2> 2296264 T6924 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[2 (1436119956693450752)]} 0 1
[junit4:junit4] 2> 2296270 T6996 C6121 P57609 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[2 (1436119956697645056)]} 0 0
[junit4:junit4] 2> 2296271 T6958 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[2 (1436119956697645056)]} 0 4
[junit4:junit4] 2> 2296275 T6926 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[3 (1436119956704985088)]} 0 1
[junit4:junit4] 2> 2296286 T6997 C6121 P57609 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[3 (1436119956712325120)]} 0 1
[junit4:junit4] 2> 2296286 T6959 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[3 (1436119956712325120)]} 0 5
[junit4:junit4] 2> 2296288 T6945 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[3]} 0 10
[junit4:junit4] 2> 2296291 T6927 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[4 (1436119956722810880)]} 0 0
[junit4:junit4] 2> 2296302 T6980 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[4 (1436119956731199488)]} 0 0
[junit4:junit4] 2> 2296304 T6943 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[4 (1436119956731199488)]} 0 6
[junit4:junit4] 2> 2296305 T6960 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[4]} 0 10
[junit4:junit4] 2> 2296310 T6928 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[5 (1436119956742733824)]} 0 1
[junit4:junit4] 2> 2296318 T6992 C6121 P57609 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[5 (1436119956747976704)]} 0 0
[junit4:junit4] 2> 2296320 T6964 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[5 (1436119956747976704)]} 0 6
[junit4:junit4] 2> 2296324 T6923 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[6 (1436119956756365312)]} 0 1
[junit4:junit4] 2> 2296333 T6993 C6121 P57609 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[6 (1436119956763705344)]} 0 1
[junit4:junit4] 2> 2296334 T6962 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[6 (1436119956763705344)]} 0 5
[junit4:junit4] 2> 2296336 T6947 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[6]} 0 9
[junit4:junit4] 2> 2296340 T6925 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[7 (1436119956774191104)]} 0 0
[junit4:junit4] 2> 2296349 T6994 C6121 P57609 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[7 (1436119956779433984)]} 0 0
[junit4:junit4] 2> 2296351 T6961 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[7 (1436119956779433984)]} 0 7
[junit4:junit4] 2> 2296354 T6924 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[8 (1436119956788871168)]} 0 0
[junit4:junit4] 2> 2296362 T6976 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[8 (1436119956794114048)]} 0 1
[junit4:junit4] 2> 2296363 T6948 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[8 (1436119956794114048)]} 0 5
[junit4:junit4] 2> 2296368 T6926 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[9 (1436119956803551232)]} 0 1
[junit4:junit4] 2> 2296378 T6995 C6121 P57609 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[9 (1436119956808794112)]} 0 1
[junit4:junit4] 2> 2296380 T6958 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[9 (1436119956808794112)]} 0 7
[junit4:junit4] 2> 2296381 T6944 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[9]} 0 11
[junit4:junit4] 2> 2296385 T6927 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10 (1436119956821377024)]} 0 1
[junit4:junit4] 2> 2296394 T6975 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10 (1436119956825571328)]} 0 1
[junit4:junit4] 2> 2296395 T6946 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10 (1436119956825571328)]} 0 6
[junit4:junit4] 2> 2296400 T6928 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[11 (1436119956836057088)]} 0 1
[junit4:junit4] 2> 2296409 T6977 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[11 (1436119956842348544)]} 0 1
[junit4:junit4] 2> 2296410 T6945 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[11 (1436119956842348544)]} 0 5
[junit4:junit4] 2> 2296414 T6923 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[12 (1436119956850737152)]} 0 2
[junit4:junit4] 2> 2296424 T6978 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[12 (1436119956859125760)]} 0 1
[junit4:junit4] 2> 2296425 T6943 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[12 (1436119956859125760)]} 0 5
[junit4:junit4] 2> 2296427 T6959 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[12]} 0 10
[junit4:junit4] 2> 2296430 T6925 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[13 (1436119956868562944)]} 0 0
[junit4:junit4] 2> 2296438 T6979 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[13 (1436119956873805824)]} 0 1
[junit4:junit4] 2> 2296439 T6947 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[13 (1436119956873805824)]} 0 5
[junit4:junit4] 2> 2296443 T6924 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[14 (1436119956882194432)]} 0 0
[junit4:junit4] 2> 2296451 T6980 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[14 (1436119956886388736)]} 0 1
[junit4:junit4] 2> 2296452 T6948 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[14 (1436119956886388736)]} 0 5
[junit4:junit4] 2> 2296456 T6926 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[15 (1436119956895825920)]} 0 0
[junit4:junit4] 2> 2296465 T6976 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[15 (1436119956903165952)]} 0 0
[junit4:junit4] 2> 2296468 T6944 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[15 (1436119956903165952)]} 0 6
[junit4:junit4] 2> 2296469 T6960 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[15]} 0 10
[junit4:junit4] 2> 2296473 T6927 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[16 (1436119956912603136)]} 0 1
[junit4:junit4] 2> 2296480 T6975 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[16 (1436119956916797440)]} 0 1
[junit4:junit4] 2> 2296481 T6946 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[16 (1436119956916797440)]} 0 5
[junit4:junit4] 2> 2296485 T6928 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[17 (1436119956926234624)]} 0 0
[junit4:junit4] 2> 2296496 T6996 C6121 P57609 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[17 (1436119956934623232)]} 0 1
[junit4:junit4] 2> 2296497 T6964 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[17 (1436119956934623232)]} 0 4
[junit4:junit4] 2> 2296498 T6945 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[17]} 0 9
[junit4:junit4] 2> 2296503 T6923 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[18 (1436119956945108992)]} 0 1
[junit4:junit4] 2> 2296511 T6997 C6121 P57609 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[18 (1436119956949303296)]} 0 1
[junit4:junit4] 2> 2296512 T6962 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[18 (1436119956949303296)]} 0 6
[junit4:junit4] 2> 2296518 T6925 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[19 (1436119956960837632)]} 0 1
[junit4:junit4] 2> 2296526 T6992 C6121 P57609 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[19 (1436119956963983360)]} 0 0
[junit4:junit4] 2> 2296528 T6961 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[19 (1436119956963983360)]} 0 7
[junit4:junit4] 2> 2296532 T6924 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[20 (1436119956974469120)]} 0 1
[junit4:junit4] 2> 2296538 T6977 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[20 (1436119956979712000)]} 0 1
[junit4:junit4] 2> 2296540 T6943 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[20 (1436119956979712000)]} 0 5
[junit4:junit4] 2> 2296544 T6926 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[21 (1436119956988100608)]} 0 1
[junit4:junit4] 2> 2296551 T6993 C6121 P57609 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[21 (1436119956992294912)]} 0 1
[junit4:junit4] 2> 2296553 T6958 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[21 (1436119956992294912)]} 0 6
[junit4:junit4] 2> 2296557 T6927 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[22 (1436119957001732096)]} 0 1
[junit4:junit4] 2> 2296567 T6978 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[22 (1436119957008023552)]} 0 1
[junit4:junit4] 2> 2296569 T6947 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[22 (1436119957008023552)]} 0 6
[junit4:junit4] 2> 2296570 T6959 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[22]} 0 10
[junit4:junit4] 2> 2296574 T6928 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[23 (1436119957018509312)]} 0 1
[junit4:junit4] 2> 2296583 T6994 C6121 P57609 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[23 (1436119957025849344)]} 0 1
[junit4:junit4] 2> 2296584 T6960 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[23 (1436119957025849344)]} 0 5
[junit4:junit4] 2> 2296586 T6948 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[23]} 0 9
[junit4:junit4] 2> 2296591 T6923 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[24 (1436119957037383680)]} 0 1
[junit4:junit4] 2> 2296598 T6979 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[24 (1436119957042626560)]} 0 0
[junit4:junit4] 2> 2296601 T6944 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[24 (1436119957042626560)]} 0 6
[junit4:junit4] 2> 2296605 T6925 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[25 (1436119957051015168)]} 0 1
[junit4:junit4] 2> 2296616 T6995 C6121 P57609 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[25 (1436119957058355200)]} 0 0
[junit4:junit4] 2> 2296617 T6964 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[25 (1436119957058355200)]} 0 6
[junit4:junit4] 2> 2296619 T6946 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[25]} 0 10
[junit4:junit4] 2> 2296622 T6924 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[26 (1436119957069889536)]} 0 1
[junit4:junit4] 2> 2296633 T6996 C6121 P57609 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[26 (1436119957078278144)]} 0 1
[junit4:junit4] 2> 2296635 T6961 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[26 (1436119957078278144)]} 0 6
[junit4:junit4] 2> 2296637 T6943 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[26]} 0 12
[junit4:junit4] 2> 2296640 T6927 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[27 (1436119957088763904)]} 0 0
[junit4:junit4] 2> 2296648 T6980 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[27 (1436119957094006784)]} 0 1
[junit4:junit4] 2> 2296650 T6947 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[27 (1436119957094006784)]} 0 6
[junit4:junit4] 2> 2296654 T6928 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[28 (1436119957102395392)]} 0 1
[junit4:junit4] 2> 2296663 T6975 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[28 (1436119957110784000)]} 0 1
[junit4:junit4] 2> 2296664 T6948 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[28 (1436119957110784000)]} 0 3
[junit4:junit4] 2> 2296665 T6958 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[28]} 0 8
[junit4:junit4] 2> 2296667 T6923 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[29 (1436119957117075456)]} 0 0
[junit4:junit4] 2> 2296674 T6992 C6121 P57609 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[29 (1436119957122318336)]} 0 0
[junit4:junit4] 2> 2296675 T6959 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[29 (1436119957122318336)]} 0 3
[junit4:junit4] 2> 2296676 T6944 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[29]} 0 6
[junit4:junit4] 2> 2296678 T6925 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[30 (1436119957128609792)]} 0 0
[junit4:junit4] 2> 2296684 T6993 C6121 P57609 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[30 (1436119957131755520)]} 0 0
[junit4:junit4] 2> 2296685 T6960 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[30 (1436119957131755520)]} 0 4
[junit4:junit4] 2> 2296688 T6926 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[31 (1436119957139095552)]} 0 0
[junit4:junit4] 2> 2296693 T6994 C6121 P57609 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[31 (1436119957142241280)]} 0 0
[junit4:junit4] 2> 2296694 T6964 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[31 (1436119957142241280)]} 0 3
[junit4:junit4] 2> 2296697 T6924 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[32 (1436119957148532736)]} 0 0
[junit4:junit4] 2> 2296703 T6977 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[32 (1436119957153775616)]} 0 0
[junit4:junit4] 2> 2296704 T6945 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[32 (1436119957153775616)]} 0 2
[junit4:junit4] 2> 2296705 T6962 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[32]} 0 5
[junit4:junit4] 2> 2296707 T6927 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[33 (1436119957159018496)]} 0 0
[junit4:junit4] 2> 2296714 T6995 C6121 P57609 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[33 (1436119957164261376)]} 0 0
[junit4:junit4] 2> 2296715 T6961 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[33 (1436119957164261376)]} 0 3
[junit4:junit4] 2> 2296716 T6946 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[33]} 0 6
[junit4:junit4] 2> 2296718 T6928 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[34 (1436119957170552832)]} 0 0
[junit4:junit4] 2> 2296723 T6978 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[34 (1436119957173698560)]} 0 0
[junit4:junit4] 2> 2296724 T6943 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[34 (1436119957173698560)]} 0 3
[junit4:junit4] 2> 2296726 T6923 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[35 (1436119957178941440)]} 0 0
[junit4:junit4] 2> 2296730 T6979 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[35 (1436119957181038592)]} 0 0
[junit4:junit4] 2> 2296731 T6947 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[35 (1436119957181038592)]} 0 3
[junit4:junit4] 2> 2296733 T6925 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[36 (1436119957186281472)]} 0 0
[junit4:junit4] 2> 2296744 T6980 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[36 (1436119957196767232)]} 0 0
[junit4:junit4] 2> 2296745 T6948 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[36 (1436119957196767232)]} 0 2
[junit4:junit4] 2> 2296745 T6958 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[36]} 0 4
[junit4:junit4] 2> 2296749 T6926 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[37 (1436119957202010112)]} 0 1
[junit4:junit4] 2> 2296755 T6996 C6121 P57609 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[37 (1436119957206204416)]} 0 0
[junit4:junit4] 2> 2296756 T6959 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[37 (1436119957206204416)]} 0 4
[junit4:junit4] 2> 2296760 T6924 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[38 (1436119957214593024)]} 0 0
[junit4:junit4] 2> 2296767 T6976 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[38 (1436119957217738752)]} 0 1
[junit4:junit4] 2> 2296768 T6944 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[38 (1436119957217738752)]} 0 5
[junit4:junit4] 2> 2296772 T6927 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[39 (1436119957227175936)]} 0 0
[junit4:junit4] 2> 2296782 T6997 C6121 P57609 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[39 (1436119957234515968)]} 0 1
[junit4:junit4] 2> 2296783 T6960 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[39 (1436119957234515968)]} 0 4
[junit4:junit4] 2> 2296783 T6945 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[39]} 0 7
[junit4:junit4] 2> 2296786 T6928 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[40 (1436119957241856000)]} 0 0
[junit4:junit4] 2> 2296793 T6975 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[40 (1436119957246050304)]} 0 0
[junit4:junit4] 2> 2296794 T6946 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[40 (1436119957246050304)]} 0 4
[junit4:junit4] 2> 2296798 T6923 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[41 (1436119957254438912)]} 0 0
[junit4:junit4] 2> 2296804 T6977 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[41 (1436119957258633216)]} 0 0
[junit4:junit4] 2> 2296805 T6943 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[41 (1436119957258633216)]} 0 4
[junit4:junit4] 2> 2296808 T6925 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[42 (1436119957264924672)]} 0 0
[junit4:junit4] 2> 2296816 T6978 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[42 (1436119957270167552)]} 0 0
[junit4:junit4] 2> 2296817 T6947 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[42 (1436119957270167552)]} 0 4
[junit4:junit4] 2> 2296818 T6964 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[42]} 0 7
[junit4:junit4] 2> 2296822 T6926 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[43 (1436119957279604736)]} 0 0
[junit4:junit4] 2> 2296830 T6979 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[43 (1436119957285896192)]} 0 0
[junit4:junit4] 2> 2296831 T6948 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[43 (1436119957285896192)]} 0 3
[junit4:junit4] 2> 2296832 T6962 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[43]} 0 6
[junit4:junit4] 2> 2296836 T6924 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[44 (1436119957294284800)]} 0 0
[junit4:junit4] 2> 2296844 T6980 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[44 (1436119957300576256)]} 0 0
[junit4:junit4] 2> 2296845 T6944 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[44 (1436119957300576256)]} 0 3
[junit4:junit4] 2> 2296846 T6961 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[44]} 0 7
[junit4:junit4] 2> 2296848 T6927 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[45 (1436119957306867712)]} 0 0
[junit4:junit4] 2> 2296859 T6992 C6121 P57609 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[45 (1436119957314207744)]} 0 1
[junit4:junit4] 2> 2296860 T6958 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[45 (1436119957314207744)]} 0 5
[junit4:junit4] 2> 2296861 T6945 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[45]} 0 9
[junit4:junit4] 2> 2296865 T6928 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[46 (1436119957324693504)]} 0 1
[junit4:junit4] 2> 2296871 T6976 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[46 (1436119957328887808)]} 0 0
[junit4:junit4] 2> 2296872 T6946 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[46 (1436119957328887808)]} 0 3
[junit4:junit4] 2> 2296874 T6959 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[46]} 0 7
[junit4:junit4] 2> 2296877 T6923 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[47 (1436119957337276416)]} 0 0
[junit4:junit4] 2> 2296886 T6975 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[47 (1436119957343567872)]} 0 0
[junit4:junit4] 2> 2296888 T6943 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[47 (1436119957343567872)]} 0 5
[junit4:junit4] 2> 2296889 T6960 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[47]} 0 9
[junit4:junit4] 2> 2296891 T6925 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[48 (1436119957351956480)]} 0 0
[junit4:junit4] 2> 2296900 T6977 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[48 (1436119957358247936)]} 0 0
[junit4:junit4] 2> 2296902 T6947 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[48 (1436119957358247936)]} 0 5
[junit4:junit4] 2> 2296902 T6964 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[48]} 0 8
[junit4:junit4] 2> 2296905 T6926 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[49 (1436119957366636544)]} 0 0
[junit4:junit4] 2> 2296916 T6978 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[49 (1436119957375025152)]} 0 1
[junit4:junit4] 2> 2296918 T6948 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[49 (1436119957375025152)]} 0 5
[junit4:junit4] 2> 2296919 T6962 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[49]} 0 9
[junit4:junit4] 2> 2296923 T6924 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[50 (1436119957385510912)]} 0 1
[junit4:junit4] 2> 2296932 T6979 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[50 (1436119957390753792)]} 0 1
[junit4:junit4] 2> 2296933 T6944 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[50 (1436119957390753792)]} 0 6
[junit4:junit4] 2> 2296938 T6927 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[51 (1436119957400190976)]} 0 1
[junit4:junit4] 2> 2296945 T6980 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[51 (1436119957405433856)]} 0 1
[junit4:junit4] 2> 2296947 T6945 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[51 (1436119957405433856)]} 0 6
[junit4:junit4] 2> 2296951 T6928 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[52 (1436119957413822464)]} 0 1
[junit4:junit4] 2> 2296961 T6976 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[52 (1436119957422211072)]} 0 1
[junit4:junit4] 2> 2296962 T6946 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[52 (1436119957422211072)]} 0 5
[junit4:junit4] 2> 2296964 T6961 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[52]} 0 11
[junit4:junit4] 2> 2296969 T6923 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[53 (1436119957432696832)]} 0 1
[junit4:junit4] 2> 2296977 T6993 C6121 P57609 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[53 (1436119957437939712)]} 0 0
[junit4:junit4] 2> 2296979 T6958 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[53 (1436119957437939712)]} 0 6
[junit4:junit4] 2> 2296983 T6925 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[54 (1436119957447376896)]} 0 1
[junit4:junit4] 2> 2296993 T6975 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[54 (1436119957454716928)]} 0 0
[junit4:junit4] 2> 2296994 T6943 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[54 (1436119957454716928)]} 0 5
[junit4:junit4] 2> 2296996 T6959 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[54]} 0 10
[junit4:junit4] 2> 2297001 T6926 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[55 (1436119957467299840)]} 0 1
[junit4:junit4] 2> 2297012 T6977 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[55 (1436119957475688448)]} 0 1
[junit4:junit4] 2> 2297013 T6947 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[55 (1436119957475688448)]} 0 5
[junit4:junit4] 2> 2297015 T6960 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[55]} 0 10
[junit4:junit4] 2> 2297019 T6924 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[56 (1436119957486174208)]} 0 0
[junit4:junit4] 2> 2297048 T6994 C6121 P57609 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[56 (1436119957514485760)]} 0 0
[junit4:junit4] 2> 2297049 T6964 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[56 (1436119957514485760)]} 0 3
[junit4:junit4] 2> 2297050 T6944 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[56]} 0 13
[junit4:junit4] 2> 2297052 T6928 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[57 (1436119957520777216)]} 0 0
[junit4:junit4] 2> 2297058 T6996 C6121 P57609 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[57 (1436119957523922944)]} 0 0
[junit4:junit4] 2> 2297059 T6961 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[57 (1436119957523922944)]} 0 4
[junit4:junit4] 2> 2297061 T6923 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[58 (1436119957530214400)]} 0 0
[junit4:junit4] 2> 2297068 T6997 C6121 P57609 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[58 (1436119957533360128)]} 0 0
[junit4:junit4] 2> 2297069 T6958 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[58 (1436119957533360128)]} 0 5
[junit4:junit4] 2> 2297071 T6925 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[59 (1436119957540700160)]} 0 0
[junit4:junit4] 2> 2297079 T6978 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[59 (1436119957546991616)]} 0 0
[junit4:junit4] 2> 2297081 T6945 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[59 (1436119957546991616)]} 0 4
[junit4:junit4] 2> 2297082 T6959 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[59]} 0 8
[junit4:junit4] 2> 2297085 T6926 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[60 (1436119957555380224)]} 0 0
[junit4:junit4] 2> 2297097 T6992 C6121 P57609 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57590/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[60 (1436119957563768832)]} 0 1
[junit4:junit4] 2> 2297098 T6960 C6122 P57590 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[60 (1436119957563768832)]} 0 6
[junit4:junit4] 2> 2297100 T6946 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[60]} 0 11
[junit4:junit4] 2> 2297104 T6924 C6123 P57569 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[61 (1436119957575303168)]} 0 1
[junit4:junit4] 2> 2297116 T6980 C6120 P57599 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:57581/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[61 (1436119957583691776)]} 0 2
[junit4:junit4] 2> 2297117 T6943 C6119 P57581 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0
[...truncated too long message...]
eyShardSplitTest-1369590691131 FAILED !!!!!
[junit4:junit4] 2> 2328775 T6910 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 2328778 T6910 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:57562 57562
[junit4:junit4] 2> 2329922 T7001 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 2331008 T7001 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 2331010 T6910 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 57569
[junit4:junit4] 2> 2331043 T6910 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 2331044 T6910 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:57562 57562
[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=AC2F33F04745B64B -Dtests.slow=true -Dtests.locale=fr_FR -Dtests.timezone=Etc/UCT -Dtests.file.encoding=ISO-8859-1
[junit4:junit4] ERROR 61.6s | ChaosMonkeyShardSplitTest.testDistribSearch <<<
[junit4:junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:57581 returned non ok status:500, message:Server Error
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([AC2F33F04745B64B:2DC9BDE8301AD677]: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> 2331052 T6910 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {id=PostingsFormat(name=Direct), _version_=PostingsFormat(name=MockSep)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=fr_FR, timezone=Etc/UCT
[junit4:junit4] 2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.7.0_21 (32-bit)/cpus=2,threads=2,free=355012360,total=523501568
[junit4:junit4] 2> NOTE: All tests run in this JVM: [FileUtilsTest, TestSolrQueryParserDefaultOperatorResource, TestIndexingPerformance, FileBasedSpellCheckerTest, TestComponentsName, UUIDFieldTest, TestFoldingMultitermQuery, DocumentBuilderTest, TestDocSet, BadIndexSchemaTest, QueryElevationComponentTest, LukeRequestHandlerTest, RAMDirectoryFactoryTest, TestStressRecovery, PluginInfoTest, TestAtomicUpdateErrorCases, DirectUpdateHandlerOptimizeTest, TestCopyFieldCollectionResource, OpenCloseCoreStressTest, TestFieldTypeCollectionResource, TestJmxMonitoredMap, TestPostingsSolrHighlighter, TestDistributedSearch, TestMergePolicyConfig, TestSchemaResource, TestArbitraryIndexDir, TestStressReorder, DistanceFunctionTest, CollectionsAPIDistributedZkTest, JSONWriterTest, TestRecovery, TermsComponentTest, IndexSchemaRuntimeFieldTest, OverseerCollectionProcessorTest, TestSchemaVersionResource, UpdateParamsTest, TestSurroundQueryParser, TestPerFieldSimilarity, TestUtils, SearchHandlerTest, TestDynamicFieldCollectionResource, DisMaxRequestHandlerTest, TestValueSourceCache, TestPartialUpdateDeduplication, MinimalSchemaTest, DocValuesMultiTest, TestSearchPerf, TestSolrQueryParserResource, TestLFUCache, OverseerTest, XmlUpdateRequestHandlerTest, TestSolrIndexConfig, FastVectorHighlighterTest, ShardSplitTest, SliceStateTest, TestRemoteStreaming, TestBadConfig, UnloadDistributedZkTest, BadComponentTest, TestSerializedLuceneMatchVersion, TestRandomDVFaceting, LegacyHTMLStripCharFilterTest, ScriptEngineTest, PingRequestHandlerTest, FieldMutatingUpdateProcessorTest, DebugComponentTest, ClusterStateUpdateTest, DistributedSpellCheckComponentTest, SimplePostToolTest, PrimitiveFieldTypeTest, TestFunctionQuery, ZkNodePropsTest, SuggesterTSTTest, RecoveryZkTest, SynonymTokenizerTest, SpellingQueryConverterTest, DirectUpdateHandlerTest, TestIndexSearcher, TestZkChroot, TestBM25SimilarityFactory, TestLuceneMatchVersion, SolrRequestParserTest, SolrTestCaseJ4Test, TestRandomFaceting, BasicDistributedZk2Test, ConvertedLegacyTest, SolrInfoMBeanTest, TestDocumentBuilder, DirectSolrSpellCheckerTest, SuggesterTest, BadCopyFieldTest, StandardRequestHandlerTest, TestSuggestSpellingConverter, TestManagedSchema, TestReversedWildcardFilterFactory, TestFieldResource, DistributedTermsComponentTest, TestFaceting, TestCoreDiscovery, MBeansHandlerTest, TestSolrQueryParser, RegexBoostProcessorTest, TestSchemaSimilarityResource, SystemInfoHandlerTest, TestPseudoReturnFields, TestSolrDeletionPolicy1, LeaderElectionTest, TestPHPSerializedResponseWriter, TestSweetSpotSimilarityFactory, TestFastOutputStream, SignatureUpdateProcessorFactoryTest, CachingDirectoryFactoryTest, MoreLikeThisHandlerTest, RequiredFieldsTest, EchoParamsTest, ShardRoutingTest, TestStressVersions, TestLazyCores, DistributedQueryElevationComponentTest, SolrIndexSplitterTest, AliasIntegrationTest, NoCacheHeaderTest, DOMUtilTest, ChaosMonkeyNothingIsSafeTest, TestCSVLoader, TestUpdate, TestFastLRUCache, MultiTermTest, TestSolrXml, HighlighterConfigTest, TestGroupingSearch, TestJoin, ResourceLoaderTest, FieldAnalysisRequestHandlerTest, TestMultiCoreConfBootstrap, SimpleFacetsTest, TestWordDelimiterFilterFactory, TestManagedSchemaFieldResource, RequestHandlersTest, TestDefaultSimilarityFactory, ZkCLITest, PolyFieldTest, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, SyncSliceTest, LeaderElectionIntegrationTest, BasicZkTest, FullSolrCloudDistribCmdsTest, TestReplicationHandler, ZkSolrClientTest, ShardRoutingCustomTest, SliceStateUpdateTest, AutoCommitTest, TestDistributedGrouping, TestHashPartitioner, TermVectorComponentDistributedTest, ZkControllerTest, TestRealTimeGet, TestReload, HardAutoCommitTest, TestRangeQuery, TestCoreContainer, TestSolr4Spatial, SolrCoreTest, StatsComponentTest, SpellCheckComponentTest, SolrCmdDistributorTest, PeerSyncTest, TestSort, TestFiltering, BasicFunctionalityTest, HighlighterTest, SoftAutoCommitTest, ShowFileRequestHandlerTest, CurrencyFieldOpenExchangeTest, CurrencyFieldXmlFileTest, AnalysisAfterCoreReloadTest, TestExtendedDismaxParser, SpellCheckCollatorTest, SuggesterFSTTest, CoreAdminHandlerTest, DocValuesTest, TestStressLucene, TestTrie, SpatialFilterTest, SuggesterWFSTTest, WordBreakSolrSpellCheckerTest, SchemaVersionSpecificBehaviorTest, SolrCoreCheckLockOnStartupTest, QueryEqualityTest, DefaultValueUpdateProcessorTest, StatelessScriptUpdateProcessorFactoryTest, SortByFunctionTest, XsltUpdateRequestHandlerTest, CacheHeaderTest, IndexBasedSpellCheckerTest, TestQueryUtils, TestWriterPerf, DocumentAnalysisRequestHandlerTest, TestQueryTypes, TestOmitPositions, PathHierarchyTokenizerFactoryTest, TermVectorComponentTest, LoggingHandlerTest, SolrPluginUtilsTest, IndexSchemaTest, TestJmxIntegration, TestCollationField, ReturnFieldsTest, UpdateRequestProcessorFactoryTest, TestCSVResponseWriter, QueryParsingTest, TestAnalyzedSuggestions, UniqFieldsUpdateProcessorFactoryTest, JsonLoaderTest, BinaryUpdateRequestHandlerTest, CSVRequestHandlerTest, CoreContainerCoreInitFailuresTest, TestBinaryResponseWriter, SOLR749Test, TestPropInject, TestQuerySenderListener, TestPropInjectDefaults, IndexReaderFactoryTest, AlternateDirectoryTest, TestQuerySenderNoQuery, CopyFieldTest, ResponseLogComponentTest, SolrIndexConfigTest, TestSolrDeletionPolicy2, SampleTest, TestBinaryField, NumericFieldsTest, TestElisionMultitermQuery, TestConfig, OutputWriterTest, TestFuzzyAnalyzedSuggestions, ExternalFileFieldSortTest, TestSolrCoreProperties, DirectSolrConnectionTest, NotRequiredUniqueKeyTest, TestPhraseSuggestions, SpellPossibilityIteratorTest, TestCharFilters, TestCodecSupport, TestXIncludeConfig, TestDFRSimilarityFactory, TestNumberUtils, TestLMDirichletSimilarityFactory, TestLMJelinekMercerSimilarityFactory, TestIBSimilarityFactory, TestFastWriter, TestPluginEnable, TimeZoneUtilsTest, OpenExchangeRatesOrgProviderTest, URLClassifyProcessorTest, DateMathParserTest, TestSolrXMLSerializer, PreAnalyzedFieldTest, TestSystemIdResolver, PrimUtilsTest, DateFieldTest, ClusterStateTest, TestSolrJ, TestLRUCache, CircularListTest, TestRTGBase, ChaosMonkeyShardSplitTest]
[junit4:junit4] Completed in 61.68s, 1 test, 1 error <<< FAILURES!
[...truncated 51 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, 18 ignored (12 assumptions)
Total time: 64 minutes 19 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.7.0_21 -server -XX:+UseConcMarkSweepGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure