You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/06/18 10:32:10 UTC
[JENKINS] Lucene-Solr-trunk-Windows (32bit/jdk1.7.0_21) - Build #
2941 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/2941/
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:52863 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:52863 returned non ok status:500, message:Server Error
at __randomizedtesting.SeedInfo.seed([8A3241540D3BBC81:BD4CF4C7A64DCBD]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.cloud.ShardSplitTest.splitShard(ShardSplitTest.java:228)
at org.apache.solr.cloud.ChaosMonkeyShardSplitTest.doTest(ChaosMonkeyShardSplitTest.java:136)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.GeneratedMethodAccessor38.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 10018 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.ChaosMonkeyShardSplitTest
[junit4:junit4] 2> 2648180 T7140 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4] 2> 2648184 T7140 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-1371544139065
[junit4:junit4] 2> 2648189 T7140 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 2648189 T7141 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 2648276 T7140 oasc.ZkTestServer.run start zk server on port:52844
[junit4:junit4] 2> 2648278 T7140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2648296 T7147 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b782f8 name:ZooKeeperConnection Watcher:127.0.0.1:52844 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2648297 T7140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2648297 T7140 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 2648313 T7142 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13f5666b5410000, 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> 2648315 T7140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2648320 T7149 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1d19b40 name:ZooKeeperConnection Watcher:127.0.0.1:52844/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2648320 T7140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2648320 T7140 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 2648328 T7140 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 2648334 T7140 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 2648339 T7140 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 2648345 T7140 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> 2648346 T7140 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 2648356 T7140 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> 2648356 T7140 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 2648363 T7140 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> 2648364 T7140 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 2648394 T7140 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> 2648396 T7140 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 2648403 T7140 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> 2648403 T7140 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 2648409 T7140 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> 2648410 T7140 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 2648415 T7140 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> 2648416 T7140 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 2648421 T7140 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> 2648422 T7140 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 2648430 T7140 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> 2648430 T7140 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 2648887 T7140 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2648894 T7140 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52851
[junit4:junit4] 2> 2648895 T7140 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2648895 T7140 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2648896 T7140 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-1371544139322
[junit4:junit4] 2> 2648896 T7140 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-1371544139322\solr.xml
[junit4:junit4] 2> 2648897 T7140 oasc.CoreContainer.<init> New CoreContainer 31111943
[junit4:junit4] 2> 2648897 T7140 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-1371544139322\'
[junit4:junit4] 2> 2648898 T7140 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-1371544139322\'
[junit4:junit4] 2> 2649029 T7140 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 2649030 T7140 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2649030 T7140 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 2649030 T7140 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2649031 T7140 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2649031 T7140 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2649032 T7140 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2649032 T7140 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2649032 T7140 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2649033 T7140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 2649041 T7140 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2649042 T7140 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52844/solr
[junit4:junit4] 2> 2649042 T7140 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2649045 T7140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2649058 T7160 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1214149 name:ZooKeeperConnection Watcher:127.0.0.1:52844 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2649058 T7140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2649062 T7140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2649070 T7140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2649073 T7162 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1fdfb4f name:ZooKeeperConnection Watcher:127.0.0.1:52844/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2649073 T7140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2649077 T7140 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 2649100 T7140 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 2649107 T7140 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 2649112 T7140 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52851_
[junit4:junit4] 2> 2649114 T7140 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52851_
[junit4:junit4] 2> 2649121 T7140 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 2649134 T7140 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 2649139 T7140 oasc.Overseer.start Overseer (id=89885516698288131-127.0.0.1:52851_-n_0000000000) starting
[junit4:junit4] 2> 2649149 T7140 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 2649158 T7164 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 2649158 T7140 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 2649163 T7140 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 2649170 T7140 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2649175 T7163 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 2649179 T7165 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 2649179 T7165 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2650470 T7163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2650472 T7163 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:52851_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52851"}
[junit4:junit4] 2> 2650472 T7163 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 2650472 T7163 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 2650485 T7162 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> 2650904 T7165 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-1371544139322\collection1
[junit4:junit4] 2> 2650904 T7165 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 2650905 T7165 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2650905 T7165 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 2650907 T7165 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-1371544139322\collection1\'
[junit4:junit4] 2> 2650909 T7165 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-1371544139322/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 2650910 T7165 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-1371544139322/collection1/lib/README' to classloader
[junit4:junit4] 2> 2650968 T7165 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2651025 T7165 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2651028 T7165 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2651033 T7165 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 2651697 T7165 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2651700 T7165 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2651702 T7165 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2651708 T7165 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2651810 T7165 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2651812 T7165 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-1371544139322\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/control/data\
[junit4:junit4] 2> 2651812 T7165 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ad25b6
[junit4:junit4] 2> 2651813 T7165 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2651814 T7165 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/control/data\
[junit4:junit4] 2> 2651814 T7165 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/control/data\index/
[junit4:junit4] 2> 2651814 T7165 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063\control\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2651814 T7165 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/control/data\index
[junit4:junit4] 2> 2651820 T7165 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@511648 lockFactory=org.apache.lucene.store.NativeFSLockFactory@11b778c),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2651820 T7165 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2651825 T7165 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2651826 T7165 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2651827 T7165 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2651828 T7165 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2651829 T7165 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2651829 T7165 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2651830 T7165 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2651830 T7165 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2651831 T7165 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2651843 T7165 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2651852 T7165 oass.SolrIndexSearcher.<init> Opening Searcher@351a31 main
[junit4:junit4] 2> 2651853 T7165 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063\control\data\tlog
[junit4:junit4] 2> 2651855 T7165 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2651855 T7165 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2651861 T7165 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2651861 T7165 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52851 collection:control_collection shard:shard1
[junit4:junit4] 2> 2651861 T7166 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@351a31 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2651863 T7165 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 2651881 T7165 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2651887 T7165 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2651887 T7165 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2651887 T7165 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52851/collection1/
[junit4:junit4] 2> 2651887 T7165 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 2651887 T7165 oasc.SyncStrategy.syncToMe http://127.0.0.1:52851/collection1/ has no replicas
[junit4:junit4] 2> 2651887 T7165 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52851/collection1/
[junit4:junit4] 2> 2651888 T7165 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 2653202 T7163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2653220 T7162 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> 2653248 T7165 oasc.ZkController.register We are http://127.0.0.1:52851/collection1/ and leader is http://127.0.0.1:52851/collection1/
[junit4:junit4] 2> 2653248 T7165 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52851
[junit4:junit4] 2> 2653248 T7165 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 2653249 T7165 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 2653249 T7165 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2653253 T7165 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2653254 T7140 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 2653254 T7140 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2653254 T7140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2653265 T7140 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 2653266 T7140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2653271 T7169 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7d1320 name:ZooKeeperConnection Watcher:127.0.0.1:52844/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2653271 T7140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2653273 T7140 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2653277 T7140 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 2653744 T7140 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2653750 T7140 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52863
[junit4:junit4] 2> 2653750 T7140 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2653751 T7140 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2653751 T7140 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-1371544144155
[junit4:junit4] 2> 2653752 T7140 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-1371544144155\solr.xml
[junit4:junit4] 2> 2653752 T7140 oasc.CoreContainer.<init> New CoreContainer 17129763
[junit4:junit4] 2> 2653753 T7140 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-1371544144155\'
[junit4:junit4] 2> 2653753 T7140 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-1371544144155\'
[junit4:junit4] 2> 2653878 T7140 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 2653879 T7140 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2653880 T7140 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 2653880 T7140 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2653880 T7140 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2653881 T7140 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2653881 T7140 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2653882 T7140 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2653882 T7140 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2653883 T7140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 2653891 T7140 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2653892 T7140 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52844/solr
[junit4:junit4] 2> 2653892 T7140 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2653894 T7140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2653912 T7180 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10488e5 name:ZooKeeperConnection Watcher:127.0.0.1:52844 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2653913 T7140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2653916 T7140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2653926 T7140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2653929 T7182 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@658e4 name:ZooKeeperConnection Watcher:127.0.0.1:52844/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2653930 T7140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2653938 T7140 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2654651 T7163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2654653 T7163 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:52851__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:52851_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52851"}
[junit4:junit4] 2> 2654666 T7169 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> 2654667 T7182 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> 2654667 T7162 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> 2654890 T7140 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52863_
[junit4:junit4] 2> 2654893 T7140 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52863_
[junit4:junit4] 2> 2654899 T7182 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> 2654900 T7162 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 2654900 T7162 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> 2654901 T7169 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 2654901 T7169 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> 2654905 T7182 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 2654917 T7183 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 2654917 T7183 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2656094 T7163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2656096 T7163 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:52863_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52863"}
[junit4:junit4] 2> 2656096 T7163 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 2656096 T7163 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 2656135 T7169 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> 2656136 T7182 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> 2656139 T7162 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> 2656811 T7183 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-1371544144155\collection1
[junit4:junit4] 2> 2656811 T7183 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 2656813 T7183 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2656814 T7183 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 2656818 T7183 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-1371544144155\collection1\'
[junit4:junit4] 2> 2656821 T7183 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-1371544144155/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 2656822 T7183 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-1371544144155/collection1/lib/README' to classloader
[junit4:junit4] 2> 2656895 T7183 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2657015 T7183 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2657019 T7183 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2657027 T7183 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 2657844 T7183 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2657849 T7183 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2657852 T7183 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2657860 T7183 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2657906 T7183 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2657908 T7183 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-1371544144155\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/jetty1\
[junit4:junit4] 2> 2657908 T7183 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ad25b6
[junit4:junit4] 2> 2657908 T7183 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2657909 T7183 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/jetty1\
[junit4:junit4] 2> 2657910 T7183 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/jetty1\index/
[junit4:junit4] 2> 2657910 T7183 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063\jetty1\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2657910 T7183 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/jetty1\index
[junit4:junit4] 2> 2657916 T7183 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1db0802 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1ad8e46),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2657917 T7183 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2657923 T7183 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2657924 T7183 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2657924 T7183 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2657925 T7183 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2657927 T7183 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2657927 T7183 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2657928 T7183 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2657928 T7183 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2657929 T7183 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2657943 T7183 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2657956 T7183 oass.SolrIndexSearcher.<init> Opening Searcher@1fefa24 main
[junit4:junit4] 2> 2657957 T7183 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063\jetty1\tlog
[junit4:junit4] 2> 2657959 T7183 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2657960 T7183 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2657968 T7183 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2657969 T7183 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52863 collection:collection1 shard:shard1
[junit4:junit4] 2> 2657970 T7183 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 2657977 T7184 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1fefa24 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2657991 T7183 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2657999 T7183 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2657999 T7183 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2657999 T7183 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52863/collection1/
[junit4:junit4] 2> 2658000 T7183 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 2658000 T7183 oasc.SyncStrategy.syncToMe http://127.0.0.1:52863/collection1/ has no replicas
[junit4:junit4] 2> 2658000 T7183 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52863/collection1/
[junit4:junit4] 2> 2658001 T7183 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 2658997 T7163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2659019 T7169 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> 2659019 T7162 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> 2659019 T7182 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> 2659023 T7183 oasc.ZkController.register We are http://127.0.0.1:52863/collection1/ and leader is http://127.0.0.1:52863/collection1/
[junit4:junit4] 2> 2659023 T7183 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52863
[junit4:junit4] 2> 2659024 T7183 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 2659024 T7183 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 2659025 T7183 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2659030 T7183 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2659032 T7140 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 2659032 T7140 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2659033 T7140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2659574 T7140 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2659579 T7140 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52872
[junit4:junit4] 2> 2659581 T7140 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2659581 T7140 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2659582 T7140 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-1371544149919
[junit4:junit4] 2> 2659582 T7140 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-1371544149919\solr.xml
[junit4:junit4] 2> 2659583 T7140 oasc.CoreContainer.<init> New CoreContainer 29257670
[junit4:junit4] 2> 2659584 T7140 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-1371544149919\'
[junit4:junit4] 2> 2659584 T7140 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-1371544149919\'
[junit4:junit4] 2> 2659756 T7140 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 2659756 T7140 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2659757 T7140 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 2659757 T7140 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2659757 T7140 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2659758 T7140 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2659759 T7140 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2659760 T7140 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2659760 T7140 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2659761 T7140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 2659773 T7140 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2659775 T7140 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52844/solr
[junit4:junit4] 2> 2659775 T7140 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2659778 T7140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2659798 T7196 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d76a7d name:ZooKeeperConnection Watcher:127.0.0.1:52844 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2659798 T7140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2659802 T7140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2659803 T7142 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13f5666b5410007, 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> 2659824 T7140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2659834 T7198 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2a7c76 name:ZooKeeperConnection Watcher:127.0.0.1:52844/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2659835 T7140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2659844 T7140 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2660453 T7163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2660454 T7163 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:52863__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:52863_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52863"}
[junit4:junit4] 2> 2660469 T7169 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> 2660469 T7182 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> 2660470 T7198 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> 2660471 T7162 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> 2660796 T7140 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52872_
[junit4:junit4] 2> 2660799 T7140 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52872_
[junit4:junit4] 2> 2660805 T7182 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> 2660806 T7169 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2660807 T7169 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> 2660807 T7162 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2660808 T7198 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2660809 T7198 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> 2660808 T7162 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> 2660811 T7182 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 2660822 T7199 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 2660823 T7199 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2661906 T7163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2661908 T7163 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:52872_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52872"}
[junit4:junit4] 2> 2661908 T7163 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 2661908 T7163 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 2661928 T7182 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> 2661929 T7162 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> 2661930 T7169 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> 2661930 T7198 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> 2662805 T7199 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-1371544149919\collection1
[junit4:junit4] 2> 2662805 T7199 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 2662806 T7199 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2662807 T7199 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 2662812 T7199 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-1371544149919\collection1\'
[junit4:junit4] 2> 2662814 T7199 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-1371544149919/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 2662816 T7199 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-1371544149919/collection1/lib/README' to classloader
[junit4:junit4] 2> 2662889 T7199 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2662967 T7199 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2662971 T7199 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2662980 T7199 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 2663626 T7199 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2663630 T7199 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2663632 T7199 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2663638 T7199 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2663678 T7199 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2663678 T7199 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-1371544149919\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/jetty2\
[junit4:junit4] 2> 2663679 T7199 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ad25b6
[junit4:junit4] 2> 2663679 T7199 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2663680 T7199 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/jetty2\
[junit4:junit4] 2> 2663681 T7199 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/jetty2\index/
[junit4:junit4] 2> 2663681 T7199 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063\jetty2\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2663682 T7199 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/jetty2\index
[junit4:junit4] 2> 2663688 T7199 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@625760 lockFactory=org.apache.lucene.store.NativeFSLockFactory@a71111),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2663688 T7199 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2663694 T7199 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2663694 T7199 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2663695 T7199 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2663696 T7199 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2663697 T7199 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2663697 T7199 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2663698 T7199 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2663699 T7199 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2663699 T7199 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2663716 T7199 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2663723 T7199 oass.SolrIndexSearcher.<init> Opening Searcher@7b0306 main
[junit4:junit4] 2> 2663723 T7199 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063\jetty2\tlog
[junit4:junit4] 2> 2663725 T7199 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2663725 T7199 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2663732 T7200 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7b0306 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2663735 T7199 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2663735 T7199 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52872 collection:collection1 shard:shard2
[junit4:junit4] 2> 2663736 T7199 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 2663751 T7199 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2663758 T7199 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2663758 T7199 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2663758 T7199 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:52872/collection1/
[junit4:junit4] 2> 2663758 T7199 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 2663759 T7199 oasc.SyncStrategy.syncToMe http://127.0.0.1:52872/collection1/ has no replicas
[junit4:junit4] 2> 2663759 T7199 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:52872/collection1/
[junit4:junit4] 2> 2663759 T7199 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 2665063 T7163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2665095 T7169 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> 2665096 T7162 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> 2665096 T7198 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> 2665096 T7182 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> 2665105 T7199 oasc.ZkController.register We are http://127.0.0.1:52872/collection1/ and leader is http://127.0.0.1:52872/collection1/
[junit4:junit4] 2> 2665105 T7199 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52872
[junit4:junit4] 2> 2665105 T7199 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 2665105 T7199 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 2665106 T7199 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2665111 T7199 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2665113 T7140 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 2665114 T7140 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2665114 T7140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2665551 T7140 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2665557 T7140 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52881
[junit4:junit4] 2> 2665557 T7140 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2665558 T7140 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2665559 T7140 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-1371544156001
[junit4:junit4] 2> 2665559 T7140 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-1371544156001\solr.xml
[junit4:junit4] 2> 2665560 T7140 oasc.CoreContainer.<init> New CoreContainer 9993384
[junit4:junit4] 2> 2665560 T7140 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-1371544156001\'
[junit4:junit4] 2> 2665561 T7140 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-1371544156001\'
[junit4:junit4] 2> 2665682 T7140 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 2665682 T7140 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2665683 T7140 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 2665683 T7140 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2665684 T7140 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2665684 T7140 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2665685 T7140 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2665685 T7140 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2665685 T7140 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2665685 T7140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 2665695 T7140 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2665696 T7140 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52844/solr
[junit4:junit4] 2> 2665697 T7140 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2665699 T7140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2665715 T7212 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@bdab2a name:ZooKeeperConnection Watcher:127.0.0.1:52844 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2665715 T7140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2665718 T7140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2665720 T7142 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13f5666b5410009, 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> 2665728 T7140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2665733 T7214 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6f3ecd name:ZooKeeperConnection Watcher:127.0.0.1:52844/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2665733 T7140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2665743 T7140 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2666674 T7163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2666675 T7163 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:52872__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:52872_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52872"}
[junit4:junit4] 2> 2666692 T7169 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> 2666692 T7162 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> 2666693 T7198 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> 2666692 T7182 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> 2666693 T7214 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> 2666788 T7140 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52881_
[junit4:junit4] 2> 2666791 T7140 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52881_
[junit4:junit4] 2> 2666796 T7182 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> 2666798 T7214 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> 2666799 T7169 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2666799 T7169 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> 2666800 T7162 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2666801 T7162 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> 2666802 T7198 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2666802 T7198 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> 2666807 T7214 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2666809 T7182 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 2666818 T7215 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 2666818 T7215 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2668264 T7163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2668265 T7163 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:52881_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52881"}
[junit4:junit4] 2> 2668265 T7163 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 2668265 T7163 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 2668283 T7169 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> 2668283 T7214 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> 2668283 T7182 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> 2668283 T7198 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> 2668283 T7162 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> 2668900 T7215 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-1371544156001\collection1
[junit4:junit4] 2> 2668900 T7215 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 2668901 T7215 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2668901 T7215 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 2668905 T7215 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-1371544156001\collection1\'
[junit4:junit4] 2> 2668907 T7215 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-1371544156001/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 2668908 T7215 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-1371544156001/collection1/lib/README' to classloader
[junit4:junit4] 2> 2668993 T7215 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2669104 T7215 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2669108 T7215 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2669117 T7215 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 2669946 T7215 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2669951 T7215 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2669954 T7215 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2669962 T7215 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2670000 T7215 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2670001 T7215 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-1371544156001\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/jetty3\
[junit4:junit4] 2> 2670001 T7215 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ad25b6
[junit4:junit4] 2> 2670002 T7215 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2670002 T7215 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/jetty3\
[junit4:junit4] 2> 2670002 T7215 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/jetty3\index/
[junit4:junit4] 2> 2670002 T7215 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063\jetty3\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2670004 T7215 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/jetty3\index
[junit4:junit4] 2> 2670008 T7215 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1768afa lockFactory=org.apache.lucene.store.NativeFSLockFactory@2fa64d),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2670008 T7215 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2670013 T7215 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2670013 T7215 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2670014 T7215 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2670015 T7215 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2670015 T7215 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2670015 T7215 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2670015 T7215 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2670017 T7215 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2670017 T7215 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2670030 T7215 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2670038 T7215 oass.SolrIndexSearcher.<init> Opening Searcher@16e2635 main
[junit4:junit4] 2> 2670038 T7215 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063\jetty3\tlog
[junit4:junit4] 2> 2670040 T7215 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2670040 T7215 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2670046 T7216 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@16e2635 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2670049 T7215 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2670049 T7215 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52881 collection:collection1 shard:shard1
[junit4:junit4] 2> 2670061 T7215 oasc.ZkController.register We are http://127.0.0.1:52881/collection1/ and leader is http://127.0.0.1:52863/collection1/
[junit4:junit4] 2> 2670061 T7215 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52881
[junit4:junit4] 2> 2670062 T7215 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 2670062 T7215 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C5808 name=collection1 org.apache.solr.core.SolrCore@4fe57f url=http://127.0.0.1:52881/collection1 node=127.0.0.1:52881_ C5808_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:52881_, base_url=http://127.0.0.1:52881}
[junit4:junit4] 2> 2670063 T7217 C5808 P52881 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 2670064 T7217 C5808 P52881 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 2670064 T7217 C5808 P52881 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 2670064 T7217 C5808 P52881 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2670065 T7215 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2670070 T7217 C5808 P52881 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2670073 T7140 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 2670073 T7140 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2670074 T7140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2670095 T7173 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:52881__collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 2670609 T7140 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 2670614 T7140 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:52891
[junit4:junit4] 2> 2670615 T7140 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 2670615 T7140 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 2670615 T7140 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-1371544160970
[junit4:junit4] 2> 2670616 T7140 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-1371544160970\solr.xml
[junit4:junit4] 2> 2670616 T7140 oasc.CoreContainer.<init> New CoreContainer 14776695
[junit4:junit4] 2> 2670617 T7140 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-1371544160970\'
[junit4:junit4] 2> 2670618 T7140 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-1371544160970\'
[junit4:junit4] 2> 2670738 T7140 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 2670738 T7140 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 2670740 T7140 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 2670740 T7140 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 2670741 T7140 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 2670741 T7140 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 2670742 T7140 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 2670742 T7140 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 2670742 T7140 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 2670742 T7140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 2670752 T7140 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 2670753 T7140 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:52844/solr
[junit4:junit4] 2> 2670753 T7140 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 2670756 T7140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2670778 T7229 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@430478 name:ZooKeeperConnection Watcher:127.0.0.1:52844 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2670778 T7140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2670781 T7140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 2670782 T7142 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13f5666b541000b, 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> 2670791 T7140 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 2670796 T7231 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3ae3bb name:ZooKeeperConnection Watcher:127.0.0.1:52844/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 2670796 T7140 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 2670806 T7140 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 2671418 T7163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2671419 T7163 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:52881__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:52881_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52881"}
[junit4:junit4] 2> 2671433 T7231 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> 2671434 T7182 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> 2671435 T7162 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> 2671435 T7198 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> 2671434 T7169 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> 2671436 T7214 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> 2671851 T7140 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:52891_
[junit4:junit4] 2> 2671855 T7140 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:52891_
[junit4:junit4] 2> 2671860 T7182 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> 2671861 T7214 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> 2671862 T7169 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2671862 T7169 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> 2671863 T7231 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2671864 T7231 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> 2671864 T7162 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2671864 T7162 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> 2671865 T7198 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2671866 T7198 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> 2671871 T7182 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2671871 T7214 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 2671880 T7232 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 2671881 T7232 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2672175 T7173 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:52881__collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 2672175 T7173 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:52881__collection1&state=recovering&nodeName=127.0.0.1:52881_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2080
[junit4:junit4] 2> 2673087 T7163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2673088 T7163 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:52891_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52891"}
[junit4:junit4] 2> 2673088 T7163 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 2673088 T7163 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 2673108 T7231 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> 2673109 T7169 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> 2673109 T7182 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> 2673110 T7162 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> 2673110 T7198 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> 2673110 T7214 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> 2674138 T7232 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-1371544160970\collection1
[junit4:junit4] 2> 2674138 T7232 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 2674139 T7232 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 2674139 T7232 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 2674143 T7232 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-1371544160970\collection1\'
[junit4:junit4] 2> 2674147 T7232 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-1371544160970/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 2674147 T7232 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-1371544160970/collection1/lib/README' to classloader
[junit4:junit4] 2> 2674240 T7232 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 2674318 T7232 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2674322 T7232 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 2674351 T7232 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> ASYNC NEW_CORE C5809 name=collection1 org.apache.solr.core.SolrCore@4fe57f url=http://127.0.0.1:52881/collection1 node=127.0.0.1:52881_ C5809_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:52881_, base_url=http://127.0.0.1:52881}
[junit4:junit4] 2> 2674475 T7217 C5809 P52881 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:52863/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 2674475 T7217 C5809 P52881 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:52881 START replicas=[http://127.0.0.1:52863/collection1/] nUpdates=100
[junit4:junit4] 2> 2674476 T7217 C5809 P52881 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 2674477 T7217 C5809 P52881 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 2674477 T7217 C5809 P52881 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 2674477 T7217 C5809 P52881 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 2674477 T7217 C5809 P52881 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 2674479 T7217 C5809 P52881 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:52863/collection1/. core=collection1
[junit4:junit4] 2> 2674479 T7217 C5809 P52881 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C5810 name=collection1 org.apache.solr.core.SolrCore@1cbd46d url=http://127.0.0.1:52863/collection1 node=127.0.0.1:52863_ C5810_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:52863_, base_url=http://127.0.0.1:52863, leader=true}
[junit4:junit4] 2> 2674500 T7175 C5810 P52863 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> 2674508 T7174 C5810 P52863 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2674513 T7174 C5810 P52863 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1db0802 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1ad8e46),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2674514 T7174 C5810 P52863 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2674514 T7174 C5810 P52863 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1db0802 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1ad8e46),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1db0802 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1ad8e46),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2674514 T7174 C5810 P52863 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2674515 T7174 C5810 P52863 oass.SolrIndexSearcher.<init> Opening Searcher@1d9b04e realtime
[junit4:junit4] 2> 2674515 T7174 C5810 P52863 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2674517 T7174 C5810 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 10
[junit4:junit4] 2> 2674519 T7217 C5809 P52881 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2674519 T7217 C5809 P52881 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 2674523 T7177 C5810 P52863 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2674523 T7177 C5810 P52863 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=2
[junit4:junit4] 2> 2674524 T7217 C5809 P52881 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 2674524 T7217 C5809 P52881 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 2674524 T7217 C5809 P52881 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 2674528 T7178 C5810 P52863 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=1
[junit4:junit4] 2> 2674528 T7217 C5809 P52881 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 2674529 T7217 C5809 P52881 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/jetty3\index.20130618112925406
[junit4:junit4] 2> 2674530 T7217 C5809 P52881 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@1ef7337 lockFactory=org.apache.lucene.store.NativeFSLockFactory@13475c9) fullCopy=false
[junit4:junit4] 2> 2674532 T7173 C5810 P52863 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> 2674534 T7217 C5809 P52881 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 2674537 T7217 C5809 P52881 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 2674538 T7217 C5809 P52881 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 2674542 T7217 C5809 P52881 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1768afa lockFactory=org.apache.lucene.store.NativeFSLockFactory@2fa64d),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1768afa lockFactory=org.apache.lucene.store.NativeFSLockFactory@2fa64d),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2674543 T7217 C5809 P52881 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2674543 T7217 C5809 P52881 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 2674543 T7217 C5809 P52881 oass.SolrIndexSearcher.<init> Opening Searcher@780958 main
[junit4:junit4] 2> 2674544 T7216 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@780958 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2674546 T7217 C5809 P52881 oasc.CachingDirectoryFactory.closeCacheValue looking to close .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/jetty3\index.20130618112925406 [CachedDir<<refCount=0;path=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/jetty3\index.20130618112925406;done=true>>]
[junit4:junit4] 2> 2674546 T7217 C5809 P52881 oasc.CachingDirectoryFactory.close Closing directory: .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/jetty3\index.20130618112925406
[junit4:junit4] 2> 2674546 T7217 C5809 P52881 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/jetty3\index.20130618112925406
[junit4:junit4] 2> 2674546 T7217 C5809 P52881 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 2674546 T7217 C5809 P52881 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 2674546 T7217 C5809 P52881 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 2674547 T7217 C5809 P52881 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2674555 T7217 C5809 P52881 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 2674839 T7163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2674842 T7163 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:52881__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:52881_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52881"}
[junit4:junit4] 2> 2674858 T7231 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> 2674858 T7169 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> 2674861 T7182 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> 2674862 T7162 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> 2674862 T7198 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> 2674863 T7214 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> 2675114 T7232 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 2675120 T7232 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 2675122 T7232 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2675128 T7232 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 2675166 T7232 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2675166 T7232 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-1371544160970\collection1\, dataDir=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/jetty4\
[junit4:junit4] 2> 2675166 T7232 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@1ad25b6
[junit4:junit4] 2> 2675167 T7232 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 2675167 T7232 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/jetty4\
[junit4:junit4] 2> 2675168 T7232 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/jetty4\index/
[junit4:junit4] 2> 2675168 T7232 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063\jetty4\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 2675168 T7232 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/jetty4\index
[junit4:junit4] 2> 2675173 T7232 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@cb6532 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16ed90e),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2675173 T7232 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2675178 T7232 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 2675178 T7232 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 2675179 T7232 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 2675180 T7232 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 2675180 T7232 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 2675181 T7232 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 2675181 T7232 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 2675182 T7232 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 2675182 T7232 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 2675195 T7232 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 2675204 T7232 oass.SolrIndexSearcher.<init> Opening Searcher@1ed469b main
[junit4:junit4] 2> 2675205 T7232 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063\jetty4\tlog
[junit4:junit4] 2> 2675206 T7232 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 2675206 T7232 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 2675214 T7235 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1ed469b main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 2675215 T7232 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2675215 T7232 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:52891 collection:collection1 shard:shard2
[junit4:junit4] 2> 2675223 T7232 oasc.ZkController.register We are http://127.0.0.1:52891/collection1/ and leader is http://127.0.0.1:52872/collection1/
[junit4:junit4] 2> 2675223 T7232 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:52891
[junit4:junit4] 2> 2675224 T7232 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 2675224 T7232 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C5811 name=collection1 org.apache.solr.core.SolrCore@1987f94 url=http://127.0.0.1:52891/collection1 node=127.0.0.1:52891_ C5811_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:52891_, base_url=http://127.0.0.1:52891}
[junit4:junit4] 2> 2675225 T7236 C5811 P52891 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 2675225 T7236 C5811 P52891 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 2675225 T7236 C5811 P52891 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 2675225 T7236 C5811 P52891 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2675225 T7232 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2675228 T7236 C5811 P52891 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2675229 T7140 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 2675229 T7140 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 2675230 T7140 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 2675240 T7140 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2675240 T7193 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:52891__collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 2675242 T7140 oasc.AbstractFullDistribZkTestBase.waitForThingsToLevelOut Wait for recoveries to finish - wait 15 for each attempt
[junit4:junit4] 2> 2675242 T7140 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):15
[junit4:junit4] 2> 2675243 T7140 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2676389 T7140 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2676595 T7163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2676598 T7163 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:52891__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:52891_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52891"}
[junit4:junit4] 2> 2676612 T7231 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> 2676613 T7162 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> 2676614 T7198 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> 2676614 T7214 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> 2676613 T7182 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> 2676613 T7169 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> 2677528 T7193 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:52891__collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 2677528 T7193 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:52891__collection1&state=recovering&nodeName=127.0.0.1:52891_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2288
[junit4:junit4] 2> 2677534 T7140 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2678681 T7140 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> ASYNC NEW_CORE C5812 name=collection1 org.apache.solr.core.SolrCore@1987f94 url=http://127.0.0.1:52891/collection1 node=127.0.0.1:52891_ C5812_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:52891_, base_url=http://127.0.0.1:52891}
[junit4:junit4] 2> 2679818 T7236 C5812 P52891 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:52872/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 2679818 T7236 C5812 P52891 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:52891 START replicas=[http://127.0.0.1:52872/collection1/] nUpdates=100
[junit4:junit4] 2> 2679819 T7236 C5812 P52891 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 2679819 T7236 C5812 P52891 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 2679819 T7236 C5812 P52891 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 2679819 T7236 C5812 P52891 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 2679821 T7236 C5812 P52891 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 2679822 T7236 C5812 P52891 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:52872/collection1/. core=collection1
[junit4:junit4] 2> 2679822 T7236 C5812 P52891 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C5813 name=collection1 org.apache.solr.core.SolrCore@1c95d99 url=http://127.0.0.1:52872/collection1 node=127.0.0.1:52872_ C5813_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:52872_, base_url=http://127.0.0.1:52872, leader=true}
[junit4:junit4] 2> 2679835 T7194 C5813 P52872 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> 2679837 T7140 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2679838 T7189 C5813 P52872 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2679844 T7189 C5813 P52872 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@625760 lockFactory=org.apache.lucene.store.NativeFSLockFactory@a71111),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2679844 T7189 C5813 P52872 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2679845 T7189 C5813 P52872 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@625760 lockFactory=org.apache.lucene.store.NativeFSLockFactory@a71111),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@625760 lockFactory=org.apache.lucene.store.NativeFSLockFactory@a71111),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2679845 T7189 C5813 P52872 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2679846 T7189 C5813 P52872 oass.SolrIndexSearcher.<init> Opening Searcher@1f8bca0 realtime
[junit4:junit4] 2> 2679846 T7189 C5813 P52872 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2679847 T7189 C5813 P52872 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 9
[junit4:junit4] 2> 2679848 T7236 C5812 P52891 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2679848 T7236 C5812 P52891 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 2679853 T7191 C5813 P52872 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 2679853 T7191 C5813 P52872 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=2
[junit4:junit4] 2> 2679854 T7236 C5812 P52891 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 2679854 T7236 C5812 P52891 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 2679854 T7236 C5812 P52891 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 2679856 T7190 C5813 P52872 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> 2679857 T7236 C5812 P52891 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 2679859 T7236 C5812 P52891 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/jetty4\index.20130618112930735
[junit4:junit4] 2> 2679859 T7236 C5812 P52891 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@482b26 lockFactory=org.apache.lucene.store.NativeFSLockFactory@5262a6) fullCopy=false
[junit4:junit4] 2> 2679862 T7192 C5813 P52872 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> 2679864 T7236 C5812 P52891 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 2679865 T7236 C5812 P52891 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 2679865 T7236 C5812 P52891 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 2679867 T7236 C5812 P52891 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@cb6532 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16ed90e),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@cb6532 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16ed90e),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2679867 T7236 C5812 P52891 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2679867 T7236 C5812 P52891 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 2679869 T7236 C5812 P52891 oass.SolrIndexSearcher.<init> Opening Searcher@159856c main
[junit4:junit4] 2> 2679870 T7235 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@159856c main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2679871 T7236 C5812 P52891 oasc.CachingDirectoryFactory.closeCacheValue looking to close .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/jetty4\index.20130618112930735 [CachedDir<<refCount=0;path=.\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/jetty4\index.20130618112930735;done=true>>]
[junit4:junit4] 2> 2679871 T7236 C5812 P52891 oasc.CachingDirectoryFactory.close Closing directory: .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/jetty4\index.20130618112930735
[junit4:junit4] 2> 2679871 T7236 C5812 P52891 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: .\org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371544139063/jetty4\index.20130618112930735
[junit4:junit4] 2> 2679871 T7236 C5812 P52891 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 2679871 T7236 C5812 P52891 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 2679872 T7236 C5812 P52891 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 2679872 T7236 C5812 P52891 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2679886 T7236 C5812 P52891 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 2680065 T7163 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2680067 T7163 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:52891__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:52891_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:52891"}
[junit4:junit4] 2> 2680090 T7231 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> 2680091 T7169 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> 2680092 T7182 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> 2680093 T7162 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> 2680093 T7198 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> 2680094 T7214 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> 2680989 T7140 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2680990 T7140 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: collection1
[junit4:junit4] 2> ASYNC NEW_CORE C5814 name=collection1 org.apache.solr.core.SolrCore@e512fa url=http://127.0.0.1:52851/collection1 node=127.0.0.1:52851_ C5814_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:52851_, base_url=http://127.0.0.1:52851, leader=true}
[junit4:junit4] 2> 2681007 T7154 C5814 P52851 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2681014 T7154 C5814 P52851 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@511648 lockFactory=org.apache.lucene.store.NativeFSLockFactory@11b778c),segFN=segments_1,generation=1}
[junit4:junit4] 2> 2681015 T7154 C5814 P52851 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 2681015 T7154 C5814 P52851 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@511648 lockFactory=org.apache.lucene.store.NativeFSLockFactory@11b778c),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@511648 lockFactory=org.apache.lucene.store.NativeFSLockFactory@11b778c),segFN=segments_2,generation=2}
[junit4:junit4] 2> 2681015 T7154 C5814 P52851 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 2681016 T7154 C5814 P52851 oass.SolrIndexSearcher.<init> Opening Searcher@c5f880 main
[junit4:junit4] 2> 2681017 T7154 C5814 P52851 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2681019 T7166 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@c5f880 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2681020 T7154 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 14
[junit4:junit4] 2> 2681092 T7189 C5813 P52872 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:52863/collection1/, StdNode: http://127.0.0.1:52881/collection1/, StdNode: http://127.0.0.1:52872/collection1/, StdNode: http://127.0.0.1:52891/collection1/] params:commit_end_point=true&commit=true&softCommit=false&waitSearcher=true&expungeDeletes=false
[junit4:junit4] 2> ASYNC NEW_CORE C5815 name=collection1 org.apache.solr.core.SolrCore@1cbd46d url=http://127.0.0.1:52863/collection1 node=127.0.0.1:52863_ C5815_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:52863_, base_url=http://127.0.0.1:52863, leader=true}
[junit4:junit4] 2> 2681123 T7176 C5815 P52863 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2681123 T7176 C5815 P52863 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1db0802 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1ad8e46),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1db0802 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1ad8e46),segFN=segments_3,generation=3}
[junit4:junit4] 2> 2681125 T7176 C5815 P52863 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 2681125 T7176 C5815 P52863 oass.SolrIndexSearcher.<init> Opening Searcher@1737516 main
[junit4:junit4] 2> 2681126 T7176 C5815 P52863 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2681129 T7184 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1737516 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2681129 T7176 C5815 P52863 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 6
[junit4:junit4] 2> ASYNC NEW_CORE C5816 name=collection1 org.apache.solr.core.SolrCore@4fe57f url=http://127.0.0.1:52881/collection1 node=127.0.0.1:52881_ C5816_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:52881_, base_url=http://127.0.0.1:52881}
[junit4:junit4] 2> 2681144 T7210 C5816 P52881 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2681159 T7210 C5816 P52881 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1768afa lockFactory=org.apache.lucene.store.NativeFSLockFactory@2fa64d),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1768afa lockFactory=org.apache.lucene.store.NativeFSLockFactory@2fa64d),segFN=segments_3,generation=3}
[junit4:junit4] 2> 2681159 T7210 C5816 P52881 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 2681160 T7210 C5816 P52881 oass.SolrIndexSearcher.<init> Opening Searcher@1479512 main
[junit4:junit4] 2> 2681161 T7210 C5816 P52881 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2681162 T7216 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1479512 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2681163 T7210 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 20
[junit4:junit4] 2> C5812_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:52891_, base_url=http://127.0.0.1:52891}
[junit4:junit4] 2> 2681157 T7227 C5812 P52891 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2681167 T7227 C5812 P52891 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@cb6532 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16ed90e),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@cb6532 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16ed90e),segFN=segments_3,generation=3}
[junit4:junit4] 2> 2681167 T7227 C5812 P52891 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 2681168 T7191 C5813 P52872 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2681169 T7191 C5813 P52872 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@625760 lockFactory=org.apache.lucene.store.NativeFSLockFactory@a71111),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@625760 lockFactory=org.apache.lucene.store.NativeFSLockFactory@a71111),segFN=segments_3,generation=3}
[junit4:junit4] 2> 2681170 T7191 C5813 P52872 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 2681171 T7191 C5813 P52872 oass.SolrIndexSearcher.<init> Opening Searcher@e96ef1 main
[junit4:junit4] 2> 2681171 T7191 C5813 P52872 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2681172 T7200 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@e96ef1 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2681173 T7227 C5812 P52891 oass.SolrIndexSearcher.<init> Opening Searcher@1196ba4 main
[junit4:junit4] 2> 2681174 T7227 C5812 P52891 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2681176 T7191 C5813 P52872 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> 2681177 T7235 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1196ba4 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 2681178 T7227 C5812 P52891 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 21
[junit4:junit4] 2> 2681180 T7189 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 88
[junit4:junit4] 2> 2681182 T7140 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2681189 T7177 C5815 P52863 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> 2681193 T7205 C5816 P52881 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> 2681198 T7192 C5813 P52872 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> 2681201 T7222 C5812 P52891 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> 2683495 T7154 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1438168304184197120)} 0 3
[junit4:junit4] 2> 2683520 T7205 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={update.distrib=FROMLEADER&_version_=-1438168304191537152&update.from=http://127.0.0.1:52863/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1438168304191537152)} 0 12
[junit4:junit4] 2> 2683524 T7222 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={update.distrib=FROMLEADER&_version_=-1438168304202022912&update.from=http://127.0.0.1:52872/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1438168304202022912)} 0 4
[junit4:junit4] 2> 2683525 T7192 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={update.distrib=TOLEADER&wt=javabin&version=2} {deleteByQuery=*:* (-1438168304202022912)} 0 17
[junit4:junit4] 2> 2683526 T7177 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1438168304191537152)} 0 28
[junit4:junit4] 2> 2683532 T7155 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[0 (1438168304224043008)]} 0 2
[junit4:junit4] 2> 2683543 T7206 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[0 (1438168304231383040)]} 0 1
[junit4:junit4] 2> 2683545 T7178 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[0 (1438168304231383040)]} 0 8
[junit4:junit4] 2> 2683546 T7193 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[0]} 0 11
[junit4:junit4] 2> 2683553 T7157 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[1 (1438168304247111680)]} 0 1
[junit4:junit4] 2> 2683562 T7207 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[1 (1438168304252354560)]} 0 1
[junit4:junit4] 2> 2683563 T7173 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[1 (1438168304252354560)]} 0 6
[junit4:junit4] 2> 2683565 T7156 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[2 (1438168304260743168)]} 0 0
[junit4:junit4] 2> 2683573 T7223 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[2 (1438168304263888896)]} 0 1
[junit4:junit4] 2> 2683574 T7194 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[2 (1438168304263888896)]} 0 6
[junit4:junit4] 2> 2683576 T7158 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[3 (1438168304272277504)]} 0 0
[junit4:junit4] 2> 2683586 T7224 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[3 (1438168304278568960)]} 0 0
[junit4:junit4] 2> 2683590 T7191 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[3 (1438168304278568960)]} 0 8
[junit4:junit4] 2> 2683591 T7175 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[3]} 0 11
[junit4:junit4] 2> 2683594 T7153 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[4 (1438168304290103296)]} 0 1
[junit4:junit4] 2> 2683605 T7208 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[4 (1438168304300589056)]} 0 0
[junit4:junit4] 2> 2683606 T7174 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[4 (1438168304300589056)]} 0 3
[junit4:junit4] 2> 2683611 T7189 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[4]} 0 11
[junit4:junit4] 2> 2683614 T7154 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[5 (1438168304312123392)]} 0 0
[junit4:junit4] 2> 2683627 T7225 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[5 (1438168304320512000)]} 0 2
[junit4:junit4] 2> 2683628 T7190 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[5 (1438168304320512000)]} 0 6
[junit4:junit4] 2> 2683629 T7176 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[5]} 0 10
[junit4:junit4] 2> 2683633 T7155 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[6 (1438168304330997760)]} 0 1
[junit4:junit4] 2> 2683641 T7226 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[6 (1438168304336240640)]} 0 1
[junit4:junit4] 2> 2683642 T7192 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[6 (1438168304336240640)]} 0 5
[junit4:junit4] 2> 2683646 T7157 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[7 (1438168304345677824)]} 0 0
[junit4:junit4] 2> 2683654 T7227 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[7 (1438168304349872128)]} 0 1
[junit4:junit4] 2> 2683656 T7193 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[7 (1438168304349872128)]} 0 6
[junit4:junit4] 2> 2683659 T7156 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[8 (1438168304359309312)]} 0 0
[junit4:junit4] 2> 2683671 T7209 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[8 (1438168304367697920)]} 0 0
[junit4:junit4] 2> 2683672 T7177 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[8 (1438168304367697920)]} 0 5
[junit4:junit4] 2> 2683673 T7194 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[8]} 0 10
[junit4:junit4] 2> 2683678 T7158 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[9 (1438168304378183680)]} 0 1
[junit4:junit4] 2> 2683686 T7222 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[9 (1438168304383426560)]} 0 0
[junit4:junit4] 2> 2683687 T7191 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[9 (1438168304383426560)]} 0 5
[junit4:junit4] 2> 2683691 T7153 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10 (1438168304392863744)]} 0 0
[junit4:junit4] 2> 2683699 T7210 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10 (1438168304397058048)]} 0 0
[junit4:junit4] 2> 2683700 T7178 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10 (1438168304397058048)]} 0 5
[junit4:junit4] 2> 2683703 T7154 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[11 (1438168304405446656)]} 0 0
[junit4:junit4] 2> 2683719 T7205 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[11 (1438168304412786688)]} 0 0
[junit4:junit4] 2> 2683720 T7173 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[11 (1438168304412786688)]} 0 10
[junit4:junit4] 2> 2683720 T7189 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[11]} 0 14
[junit4:junit4] 2> 2683724 T7155 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[12 (1438168304427466752)]} 0 0
[junit4:junit4] 2> 2683737 T7206 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[12 (1438168304434806784)]} 0 0
[junit4:junit4] 2> 2683740 T7175 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[12 (1438168304434806784)]} 0 9
[junit4:junit4] 2> 2683745 T7156 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[13 (1438168304449486848)]} 0 0
[junit4:junit4] 2> 2683756 T7207 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[13 (1438168304456826880)]} 0 0
[junit4:junit4] 2> 2683758 T7174 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[13 (1438168304456826880)]} 0 6
[junit4:junit4] 2> 2683759 T7190 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[13]} 0 11
[junit4:junit4] 2> 2683762 T7158 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[14 (1438168304467312640)]} 0 0
[junit4:junit4] 2> 2683770 T7208 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[14 (1438168304472555520)]} 0 0
[junit4:junit4] 2> 2683773 T7176 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[14 (1438168304472555520)]} 0 6
[junit4:junit4] 2> 2683779 T7153 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[15 (1438168304485138432)]} 0 0
[junit4:junit4] 2> 2683796 T7209 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[15 (1438168304495624192)]} 0 0
[junit4:junit4] 2> 2683799 T7177 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[15 (1438168304495624192)]} 0 10
[junit4:junit4] 2> 2683801 T7192 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[15]} 0 18
[junit4:junit4] 2> 2683805 T7154 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[16 (1438168304512401408)]} 0 0
[junit4:junit4] 2> 2683813 T7210 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[16 (1438168304518692864)]} 0 0
[junit4:junit4] 2> 2683816 T7178 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[16 (1438168304518692864)]} 0 5
[junit4:junit4] 2> 2683816 T7193 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[16]} 0 8
[junit4:junit4] 2> 2683820 T7157 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[17 (1438168304528130048)]} 0 0
[junit4:junit4] 2> 2683827 T7223 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[17 (1438168304531275776)]} 0 0
[junit4:junit4] 2> 2683828 T7194 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[17 (1438168304531275776)]} 0 5
[junit4:junit4] 2> 2683832 T7155 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[18 (1438168304540712960)]} 0 0
[junit4:junit4] 2> 2683843 T7224 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[18 (1438168304548052992)]} 0 0
[junit4:junit4] 2> 2683844 T7191 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[18 (1438168304548052992)]} 0 5
[junit4:junit4] 2> 2683845 T7173 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[18]} 0 8
[junit4:junit4] 2> 2683849 T7156 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[19 (1438168304558538752)]} 0 0
[junit4:junit4] 2> 2683859 T7225 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[19 (1438168304563781632)]} 0 1
[junit4:junit4] 2> 2683860 T7189 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[19 (1438168304563781632)]} 0 6
[junit4:junit4] 2> 2683864 T7158 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[20 (1438168304574267392)]} 0 0
[junit4:junit4] 2> 2683875 T7205 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[20 (1438168304581607424)]} 0 0
[junit4:junit4] 2> 2683876 T7175 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[20 (1438168304581607424)]} 0 5
[junit4:junit4] 2> 2683877 T7190 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[20]} 0 10
[junit4:junit4] 2> 2683882 T7153 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[21 (1438168304593141760)]} 0 0
[junit4:junit4] 2> 2683895 T7226 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[21 (1438168304601530368)]} 0 2
[junit4:junit4] 2> 2683896 T7192 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[21 (1438168304601530368)]} 0 6
[junit4:junit4] 2> 2683897 T7174 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[21]} 0 11
[junit4:junit4] 2> 2683899 T7154 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[22 (1438168304610967552)]} 0 0
[junit4:junit4] 2> 2683909 T7206 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[22 (1438168304616210432)]} 0 0
[junit4:junit4] 2> 2683912 T7177 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[22 (1438168304616210432)]} 0 6
[junit4:junit4] 2> 2683915 T7157 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[23 (1438168304627744768)]} 0 0
[junit4:junit4] 2> 2683928 T7222 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[23 (1438168304636133376)]} 0 2
[junit4:junit4] 2> 2683929 T7194 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[23 (1438168304636133376)]} 0 6
[junit4:junit4] 2> 2683930 T7178 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[23]} 0 10
[junit4:junit4] 2> 2683933 T7155 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[24 (1438168304646619136)]} 0 0
[junit4:junit4] 2> 2683941 T7208 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[24 (1438168304651862016)]} 0 0
[junit4:junit4] 2> 2683942 T7173 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[24 (1438168304651862016)]} 0 4
[junit4:junit4] 2> 2683945 T7156 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[25 (1438168304659202048)]} 0 0
[junit4:junit4] 2> 2683955 T7223 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[25 (1438168304665493504)]} 0 0
[junit4:junit4] 2> 2683956 T7191 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[25 (1438168304665493504)]} 0 5
[junit4:junit4] 2> 2683957 T7175 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[25]} 0 8
[junit4:junit4] 2> 2683961 T7158 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[26 (1438168304675979264)]} 0 0
[junit4:junit4] 2> 2683971 T7224 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[26 (1438168304681222144)]} 0 2
[junit4:junit4] 2> 2683972 T7189 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[26 (1438168304681222144)]} 0 6
[junit4:junit4] 2> 2683974 T7153 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[27 (1438168304689610752)]} 0 0
[junit4:junit4] 2> 2683983 T7209 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[27 (1438168304694853632)]} 0 0
[junit4:junit4] 2> 2683985 T7176 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[27 (1438168304694853632)]} 0 6
[junit4:junit4] 2> 2683989 T7154 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[28 (1438168304705339392)]} 0 0
[junit4:junit4] 2> 2683998 T7210 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[28 (1438168304709533696)]} 0 0
[junit4:junit4] 2> 2684000 T7174 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[28 (1438168304709533696)]} 0 7
[junit4:junit4] 2> 2684004 T7157 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[29 (1438168304721068032)]} 0 0
[junit4:junit4] 2> 2684017 T7225 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[29 (1438168304729456640)]} 0 1
[junit4:junit4] 2> 2684019 T7190 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[29 (1438168304729456640)]} 0 7
[junit4:junit4] 2> 2684020 T7177 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[29]} 0 11
[junit4:junit4] 2> 2684024 T7155 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[30 (1438168304742039552)]} 0 0
[junit4:junit4] 2> 2684033 T7226 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[30 (1438168304748331008)]} 0 0
[junit4:junit4] 2> 2684036 T7193 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[30 (1438168304748331008)]} 0 6
[junit4:junit4] 2> 2684040 T7156 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[31 (1438168304758816768)]} 0 0
[junit4:junit4] 2> 2684047 T7227 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[31 (1438168304763011072)]} 0 0
[junit4:junit4] 2> 2684049 T7192 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[31 (1438168304763011072)]} 0 5
[junit4:junit4] 2> 2684054 T7158 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[32 (1438168304772448256)]} 0 0
[junit4:junit4] 2> 2684060 T7205 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[32 (1438168304776642560)]} 0 0
[junit4:junit4] 2> 2684063 T7178 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[32 (1438168304776642560)]} 0 6
[junit4:junit4] 2> 2684067 T7153 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[33 (1438168304787128320)]} 0 0
[junit4:junit4] 2> 2684084 T7222 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[33 (1438168304799711232)]} 0 1
[junit4:junit4] 2> 2684085 T7194 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[33 (1438168304799711232)]} 0 6
[junit4:junit4] 2> 2684086 T7173 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[33]} 0 11
[junit4:junit4] 2> 2684090 T7154 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[34 (1438168304811245568)]} 0 0
[junit4:junit4] 2> 2684097 T7207 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[34 (1438168304815439872)]} 0 0
[junit4:junit4] 2> 2684098 T7175 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[34 (1438168304815439872)]} 0 4
[junit4:junit4] 2> 2684102 T7157 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[35 (1438168304823828480)]} 0 0
[junit4:junit4] 2> 2684112 T7206 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[35 (1438168304829071360)]} 0 0
[junit4:junit4] 2> 2684114 T7176 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[35 (1438168304829071360)]} 0 7
[junit4:junit4] 2> 2684118 T7155 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[36 (1438168304840605696)]} 0 0
[junit4:junit4] 2> 2684130 T7208 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[36 (1438168304850042880)]} 0 0
[junit4:junit4] 2> 2684133 T7174 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[36 (1438168304850042880)]} 0 6
[junit4:junit4] 2> 2684134 T7191 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[36]} 0 11
[junit4:junit4] 2> 2684139 T7156 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[37 (1438168304861577216)]} 0 1
[junit4:junit4] 2> 2684151 T7223 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[37 (1438168304869965824)]} 0 1
[junit4:junit4] 2> 2684153 T7189 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[37 (1438168304869965824)]} 0 7
[junit4:junit4] 2> 2684154 T7177 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[37]} 0 11
[junit4:junit4] 2> 2684157 T7153 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[38 (1438168304881500160)]} 0 0
[junit4:junit4] 2> 2684165 T7209 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[38 (1438168304885694464)]} 0 0
[junit4:junit4] 2> 2684167 T7178 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[38 (1438168304885694464)]} 0 6
[junit4:junit4] 2> 2684173 T7154 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[39 (1438168304897228800)]} 0 1
[junit4:junit4] 2> 2684185 T7224 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[39 (1438168304905617408)]} 0 2
[junit4:junit4] 2> 2684186 T7190 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[39 (1438168304905617408)]} 0 6
[junit4:junit4] 2> 2684187 T7173 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[39]} 0 10
[junit4:junit4] 2> 2684191 T7157 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[40 (1438168304915054592)]} 0 2
[junit4:junit4] 2> 2684198 T7210 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[40 (1438168304920297472)]} 0 0
[junit4:junit4] 2> 2684199 T7175 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[40 (1438168304920297472)]} 0 5
[junit4:junit4] 2> 2684203 T7155 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[41 (1438168304929734656)]} 0 0
[junit4:junit4] 2> 2684220 T7205 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[41 (1438168304939171840)]} 0 0
[junit4:junit4] 2> 2684223 T7176 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[41 (1438168304939171840)]} 0 11
[junit4:junit4] 2> 2684226 T7158 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[42 (1438168304953851904)]} 0 0
[junit4:junit4] 2> 2684239 T7207 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[42 (1438168304962240512)]} 0 2
[junit4:junit4] 2> 2684241 T7174 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[42 (1438168304962240512)]} 0 7
[junit4:junit4] 2> 2684242 T7193 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[42]} 0 12
[junit4:junit4] 2> 2684247 T7156 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[43 (1438168304974823424)]} 0 1
[junit4:junit4] 2> 2684258 T7206 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[43 (1438168304985309184)]} 0 0
[junit4:junit4] 2> 2684259 T7177 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[43 (1438168304985309184)]} 0 3
[junit4:junit4] 2> 2684259 T7192 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[43]} 0 6
[junit4:junit4] 2> 2684263 T7153 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[44 (1438168304992649216)]} 0 0
[junit4:junit4] 2> 2684277 T7208 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[44 (1438168305004183552)]} 0 0
[junit4:junit4] 2> 2684278 T7178 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[44 (1438168305004183552)]} 0 4
[junit4:junit4] 2> 2684278 T7194 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[44]} 0 10
[junit4:junit4] 2> 2684286 T7154 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[45 (1438168305016766464)]} 0 0
[junit4:junit4] 2> 2684299 T7225 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[45 (1438168305026203648)]} 0 0
[junit4:junit4] 2> 2684300 T7191 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[45 (1438168305026203648)]} 0 5
[junit4:junit4] 2> 2684301 T7173 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[45]} 0 8
[junit4:junit4] 2> 2684305 T7157 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[46 (1438168305036689408)]} 0 0
[junit4:junit4] 2> 2684316 T7209 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[46 (1438168305046126592)]} 0 0
[junit4:junit4] 2> 2684316 T7176 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[46 (1438168305046126592)]} 0 4
[junit4:junit4] 2> 2684317 T7190 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[46]} 0 8
[junit4:junit4] 2> 2684322 T7155 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[47 (1438168305053466624)]} 0 1
[junit4:junit4] 2> 2684331 T7205 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[47 (1438168305058709504)]} 0 2
[junit4:junit4] 2> 2684332 T7174 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[47 (1438168305058709504)]} 0 6
[junit4:junit4] 2> 2684336 T7158 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[48 (1438168305069195264)]} 0 0
[junit4:junit4] 2> 2684348 T7207 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[48 (1438168305077583872)]} 0 0
[junit4:junit4] 2> 2684350 T7177 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[48 (1438168305077583872)]} 0 6
[junit4:junit4] 2> 2684352 T7193 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[48]} 0 13
[junit4:junit4] 2> 2684357 T7156 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[49 (1438168305089118208)]} 0 2
[junit4:junit4] 2> 2684371 T7206 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[49 (1438168305103798272)]} 0 0
[junit4:junit4] 2> 2684374 T7178 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[49 (1438168305103798272)]} 0 5
[junit4:junit4] 2> 2684374 T7192 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[49]} 0 14
[junit4:junit4] 2> 2684377 T7153 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[50 (1438168305112186880)]} 0 0
[junit4:junit4] 2> 2684390 T7208 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[50 (1438168305121624064)]} 0 0
[junit4:junit4] 2> 2684391 T7175 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[50 (1438168305121624064)]} 0 5
[junit4:junit4] 2> 2684392 T7194 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[50]} 0 10
[junit4:junit4] 2> 2684396 T7154 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[51 (1438168305132109824)]} 0 0
[junit4:junit4] 2> 2684403 T7209 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[51 (1438168305136304128)]} 0 0
[junit4:junit4] 2> 2684406 T7173 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[51 (1438168305136304128)]} 0 6
[junit4:junit4] 2> 2684409 T7157 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[52 (1438168305144692736)]} 0 1
[junit4:junit4] 2> 2684420 T7210 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[52 (1438168305155178496)]} 0 0
[junit4:junit4] 2> 2684422 T7176 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[52 (1438168305155178496)]} 0 4
[junit4:junit4] 2> 2684423 T7189 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[52]} 0 9
[junit4:junit4] 2> 2684427 T7155 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[53 (1438168305164615680)]} 0 0
[junit4:junit4] 2> 2684434 T7227 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[53 (1438168305167761408)]} 0 0
[junit4:junit4] 2> 2684436 T7191 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[53 (1438168305167761408)]} 0 6
[junit4:junit4] 2> 2684441 T7158 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[54 (1438168305178247168)]} 0 1
[junit4:junit4] 2> 2684449 T7205 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[54 (1438168305183490048)]} 0 0
[junit4:junit4] 2> 2684450 T7174 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[54 (1438168305183490048)]} 0 5
[junit4:junit4] 2> 2684456 T7156 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[55 (1438168305193975808)]} 0 1
[junit4:junit4] 2> 2684466 T7207 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[55 (1438168305199218688)]} 0 1
[junit4:junit4] 2> 2684467 T7177 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[55 (1438168305199218688)]} 0 7
[junit4:junit4] 2> 2684471 T7153 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[56 (1438168305210753024)]} 0 0
[junit4:junit4] 2> 2684481 T7222 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[56 (1438168305217044480)]} 0 2
[junit4:junit4] 2> 2684482 T7190 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[56 (1438168305217044480)]} 0 5
[junit4:junit4] 2> 2684486 T7154 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[57 (1438168305226481664)]} 0 0
[junit4:junit4] 2> 2684500 T7223 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[57 (1438168305234870272)]} 0 1
[junit4:junit4] 2> 2684502 T7193 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[57 (1438168305234870272)]} 0 8
[junit4:junit4] 2> 2684503 T7178 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[57]} 0 13
[junit4:junit4] 2> 2684508 T7157 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[58 (1438168305247453184)]} 0 2
[junit4:junit4] 2> 2684516 T7224 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[58 (1438168305252696064)]} 0 1
[junit4:junit4] 2> 2684518 T7192 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[58 (1438168305252696064)]} 0 7
[junit4:junit4] 2> 2684521 T7155 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[59 (1438168305262133248)]} 0 1
[junit4:junit4] 2> 2684529 T7206 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[59 (1438168305267376128)]} 0 0
[junit4:junit4] 2> 2684531 T7175 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[59 (1438168305267376128)]} 0 6
[junit4:junit4] 2> 2684535 T7158 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[60 (1438168305277861888)]} 0 0
[junit4:junit4] 2> 2684543 T7226 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52872/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[60 (1438168305281007616)]} 0 1
[junit4:junit4] 2> 2684545 T7194 C5813 P52872 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[60 (1438168305281007616)]} 0 7
[junit4:junit4] 2> 2684547 T7156 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[61 (1438168305290444800)]} 0 0
[junit4:junit4] 2> 2684561 T7208 C5816 P52881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:52863/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[61 (1438168305295687680)]} 0 0
[junit4:junit4] 2> 2684562 T7173 C5815 P52863 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[61 (1438168305295687680)]} 0 10
[junit4:junit4] 2> 2684567 T7154 C5814 P52851 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[62 (1438168305311416320)]} 0 0
[junit4:junit4] 2> 2684575 T7225 C5812 P52891 oasup.LogUpdateProcessor.finish [collection1] webapp=
[...truncated too long message...]
riggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 2790306 T7231 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> 2790306 T7140 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 52851
[junit4:junit4] 2> 2790307 T7231 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 2790318 T7140 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 2790319 T7140 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:52844 52844
[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=8A3241540D3BBC81 -Dtests.slow=true -Dtests.locale=nl_BE -Dtests.timezone=Indian/Mayotte -Dtests.file.encoding=Cp1252
[junit4:junit4] ERROR 142s | ChaosMonkeyShardSplitTest.testDistribSearch <<<
[junit4:junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:52863 returned non ok status:500, message:Server Error
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([8A3241540D3BBC81:BD4CF4C7A64DCBD]:0)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4:junit4] > at org.apache.solr.cloud.ShardSplitTest.splitShard(ShardSplitTest.java:228)
[junit4:junit4] > at org.apache.solr.cloud.ChaosMonkeyShardSplitTest.doTest(ChaosMonkeyShardSplitTest.java:136)
[junit4:junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2> 2790327 T7140 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> NOTE: test params are: codec=FastCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=FAST, chunkSize=167), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=FAST, chunkSize=167)), sim=RandomSimilarityProvider(queryNorm=true,coord=no): {}, locale=nl_BE, timezone=Indian/Mayotte
[junit4:junit4] 2> NOTE: Windows 7 6.1 x86/Oracle Corporation 1.7.0_21 (32-bit)/cpus=2,threads=2,free=121139728,total=289288192
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestBadConfig, ClusterStateUpdateTest, BasicDistributedZk2Test, CurrencyFieldXmlFileTest, TestSolrJ, ZkSolrClientTest, MBeansHandlerTest, TestRangeQuery, SolrPluginUtilsTest, ScriptEngineTest, HighlighterTest, TestSchemaSimilarityResource, NumericFieldsTest, PrimUtilsTest, TestMergePolicyConfig, OverseerTest, SolrCmdDistributorTest, TestPseudoReturnFields, LeaderElectionTest, TestStressLucene, AnalysisAfterCoreReloadTest, BasicDistributedZkTest, TermsComponentTest, TestDocSet, URLClassifyProcessorTest, TestPHPSerializedResponseWriter, TestRandomFaceting, SpellCheckComponentTest, TestManagedSchema, DirectUpdateHandlerTest, SolrCoreCheckLockOnStartupTest, ChaosMonkeyNothingIsSafeTest, WordBreakSolrSpellCheckerTest, TestGroupingSearch, DirectSolrSpellCheckerTest, TestElisionMultitermQuery, LegacyHTMLStripCharFilterTest, ShardSplitTest, TestManagedSchemaFieldResource, TestDocumentBuilder, ChaosMonkeySafeLeaderTest, TermVectorComponentDistributedTest, SliceStateUpdateTest, LukeRequestHandlerTest, DistributedSpellCheckComponentTest, SolrIndexConfigTest, DirectUpdateHandlerOptimizeTest, TestDefaultSearchFieldResource, TestValueSourceCache, TestReversedWildcardFilterFactory, SolrInfoMBeanTest, TestXIncludeConfig, SuggesterTest, TestSolrQueryParserDefaultOperatorResource, SuggesterWFSTTest, DocumentBuilderTest, XsltUpdateRequestHandlerTest, PreAnalyzedFieldTest, TestAnalyzedSuggestions, SpellPossibilityIteratorTest, TestWriterPerf, RecoveryZkTest, IndexBasedSpellCheckerTest, TestAtomicUpdateErrorCases, CircularListTest, TestClassNameShortening, SpatialFilterTest, TestLMJelinekMercerSimilarityFactory, TestCoreContainer, TestReplicationHandler, TestReloadAndDeleteDocs, HardAutoCommitTest, TestSolrDeletionPolicy2, NotRequiredUniqueKeyTest, FileUtilsTest, PrimitiveFieldTypeTest, TestSolrQueryParser, ExternalFileFieldSortTest, PreAnalyzedUpdateProcessorTest, MultiTermTest, ZkNodePropsTest, TestShardHandlerFactory, ZkCLITest, TestSearchPerf, BadCopyFieldTest, BadComponentTest, TestSweetSpotSimilarityFactory, SpellCheckCollatorTest, DefaultValueUpdateProcessorTest, SearchHandlerTest, DistributedTermsComponentTest, SOLR749Test, TestDefaultSimilarityFactory, ClusterStateTest, SyncSliceTest, ReturnFieldsTest, FastVectorHighlighterTest, MoreLikeThisHandlerTest, TestFastWriter, CoreContainerCoreInitFailuresTest, TestCoreDiscovery, TestLRUCache, TestCloudManagedSchema, FileBasedSpellCheckerTest, StatelessScriptUpdateProcessorFactoryTest, BadIndexSchemaTest, TestFieldCollectionResource, TestJoin, RequestHandlersTest, AlternateDirectoryTest, AutoCommitTest, TestFastOutputStream, TestFiltering, BasicFunctionalityTest, TestRemoteStreaming, TestCSVResponseWriter, DOMUtilTest, DirectSolrConnectionTest, DisMaxRequestHandlerTest, TestCloudManagedSchemaAddField, TestFuzzyAnalyzedSuggestions, OverseerCollectionProcessorTest, LeaderElectionIntegrationTest, TestFieldResource, SynonymTokenizerTest, TestQuerySenderNoQuery, TestBM25SimilarityFactory, TestUpdate, TestQuerySenderListener, JSONWriterTest, QueryEqualityTest, TestMultiCoreConfBootstrap, TestCopyFieldCollectionResource, XmlUpdateRequestHandlerTest, FullSolrCloudDistribCmdsTest, TestTrie, SystemInfoHandlerTest, StandardRequestHandlerTest, TestSurroundQueryParser, TestLMDirichletSimilarityFactory, PeerSyncTest, TestRandomDVFaceting, UnloadDistributedZkTest, CollectionsAPIDistributedZkTest, OpenCloseCoreStressTest, ShardRoutingTest, BasicZkTest, TestZkChroot, ShardRoutingCustomTest, TestDistributedSearch, TestDistributedGrouping, TestFaceting, TestRecovery, TestHashPartitioner, ZkControllerTest, TestRealTimeGet, TestStressReorder, TestReload, TestStressVersions, SimpleFacetsTest, TestSolr4Spatial, SolrCoreTest, StatsComponentTest, QueryElevationComponentTest, ConvertedLegacyTest, TestSort, TestFunctionQuery, TestLazyCores, TestIndexSearcher, SoftAutoCommitTest, ShowFileRequestHandlerTest, CurrencyFieldOpenExchangeTest, DistributedQueryElevationComponentTest, SolrIndexSplitterTest, SimplePostToolTest, SignatureUpdateProcessorFactoryTest, TestExtendedDismaxParser, SuggesterFSTTest, CoreAdminHandlerTest, SolrRequestParserTest, TestFoldingMultitermQuery, DocValuesTest, SuggesterTSTTest, TestCSVLoader, PolyFieldTest, NoCacheHeaderTest, SchemaVersionSpecificBehaviorTest, FieldMutatingUpdateProcessorTest, TestWordDelimiterFilterFactory, SortByFunctionTest, DocValuesMultiTest, DistanceFunctionTest, TestSolrDeletionPolicy1, DebugComponentTest, CacheHeaderTest, TestQueryUtils, DocumentAnalysisRequestHandlerTest, TestQueryTypes, TestOmitPositions, PathHierarchyTokenizerFactoryTest, TermVectorComponentTest, TestIndexingPerformance, RequiredFieldsTest, FieldAnalysisRequestHandlerTest, TestArbitraryIndexDir, IndexSchemaRuntimeFieldTest, LoggingHandlerTest, RegexBoostProcessorTest, IndexSchemaTest, TestJmxIntegration, TestCollationField, UpdateRequestProcessorFactoryTest, QueryParsingTest, UniqFieldsUpdateProcessorFactoryTest, JsonLoaderTest, BinaryUpdateRequestHandlerTest, TestPartialUpdateDeduplication, PingRequestHandlerTest, CSVRequestHandlerTest, TestComponentsName, TestBinaryResponseWriter, TestLFUCache, HighlighterConfigTest, TestPropInject, TestPropInjectDefaults, IndexReaderFactoryTest, UpdateParamsTest, TestSolrIndexConfig, CopyFieldTest, ResponseLogComponentTest, TestStressRecovery, SampleTest, TestBinaryField, MinimalSchemaTest, TestConfig, OutputWriterTest, TestSolrCoreProperties, TestPostingsSolrHighlighter, TestLuceneMatchVersion, TestPhraseSuggestions, TestCharFilters, TestCodecSupport, EchoParamsTest, TestDFRSimilarityFactory, TestPerFieldSimilarity, TestNumberUtils, TestIBSimilarityFactory, TestJmxMonitoredMap, TestPluginEnable, TimeZoneUtilsTest, ResourceLoaderTest, OpenExchangeRatesOrgProviderTest, PluginInfoTest, TestFastLRUCache, DateMathParserTest, TestSolrXMLSerializer, TestSystemIdResolver, TestSuggestSpellingConverter, DateFieldTest, SpellingQueryConverterTest, RAMDirectoryFactoryTest, TestUtils, SliceStateTest, UUIDFieldTest, TestRTGBase, SolrTestCaseJ4Test, AliasIntegrationTest, ChaosMonkeyShardSplitTest]
[junit4:junit4] Completed in 142.18s, 1 test, 1 error <<< FAILURES!
[...truncated 57 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:386: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:366: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:181: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:437: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1243: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:887: There were test failures: 297 suites, 1250 tests, 1 error, 18 ignored (12 assumptions)
Total time: 71 minutes 11 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