You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/06/15 19:10:02 UTC
[JENKINS] Lucene-Solr-4.x-Windows (32bit/jdk1.6.0_45) - Build #
2894 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Windows/2894/
Java: 32bit/jdk1.6.0_45 -client -XX:+UseSerialGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.RecoveryZkTest.testDistribSearch
Error Message:
expected:<186> but was:<38>
Stack Trace:
java.lang.AssertionError: expected:<186> but was:<38>
at __randomizedtesting.SeedInfo.seed([7E4C8BD163DD3574:FFAA05C914825548]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.junit.Assert.assertEquals(Assert.java:456)
at org.apache.solr.cloud.RecoveryZkTest.doTest(RecoveryZkTest.java:108)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
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:662)
Build Log:
[...truncated 8792 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.RecoveryZkTest
[junit4:junit4] 2> 213312 T642 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /we_j/g
[junit4:junit4] 2> 213315 T642 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\solrtest-RecoveryZkTest-1371313535639
[junit4:junit4] 2> 213317 T642 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 213318 T643 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 213419 T642 oasc.ZkTestServer.run start zk server on port:63384
[junit4:junit4] 2> 213421 T642 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 213428 T649 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@192223 name:ZooKeeperConnection Watcher:127.0.0.1:63384 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 213429 T642 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 213429 T642 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 213437 T642 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 213441 T651 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b5889c name:ZooKeeperConnection Watcher:127.0.0.1:63384/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 213441 T642 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 213441 T642 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 213447 T642 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 213452 T642 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 213457 T642 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 213463 T642 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 213463 T642 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 213473 T642 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 213474 T642 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 213480 T642 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 213480 T642 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 213484 T642 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 213485 T642 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 213497 T642 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 213497 T642 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 213516 T642 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 213517 T642 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 213523 T642 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 213523 T642 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 213530 T642 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 213531 T642 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 213537 T642 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 213538 T642 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 213974 T642 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 213981 T642 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:63391
[junit4:junit4] 2> 213981 T642 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 213982 T642 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 213982 T642 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1371313535869
[junit4:junit4] 2> 213982 T642 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1371313535869\solr.xml
[junit4:junit4] 2> 213982 T642 oasc.CoreContainer.<init> New CoreContainer 5290060
[junit4:junit4] 2> 213982 T642 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1371313535869\'
[junit4:junit4] 2> 213983 T642 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1371313535869\'
[junit4:junit4] 2> 214109 T642 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 214109 T642 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 214110 T642 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 214110 T642 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 214110 T642 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 214111 T642 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 214111 T642 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 214111 T642 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 214112 T642 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 214112 T642 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 214121 T642 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 214122 T642 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:63384/solr
[junit4:junit4] 2> 214122 T642 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 214124 T642 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 214146 T662 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@147afda name:ZooKeeperConnection Watcher:127.0.0.1:63384 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 214147 T642 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 214150 T642 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 214153 T644 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13f48a7faa00002, 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:662)
[junit4:junit4] 2>
[junit4:junit4] 2> 214157 T642 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 214165 T664 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1118892 name:ZooKeeperConnection Watcher:127.0.0.1:63384/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 214165 T642 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 214171 T642 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 214180 T642 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 214190 T642 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 214192 T642 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63391_we_j%2Fg
[junit4:junit4] 2> 214196 T642 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:63391_we_j%2Fg
[junit4:junit4] 2> 214206 T642 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 214223 T642 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 214230 T642 oasc.Overseer.start Overseer (id=89870403872227331-127.0.0.1:63391_we_j%2Fg-n_0000000000) starting
[junit4:junit4] 2> 214241 T642 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 214255 T666 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 214256 T642 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 214261 T642 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 214265 T642 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 214269 T665 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 214274 T667 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 214274 T667 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 215774 T665 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 215775 T665 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:63391_we_j%2Fg",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63391/we_j/g"}
[junit4:junit4] 2> 215775 T665 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 215775 T665 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 215789 T664 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> 216276 T667 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1371313535869\collection1
[junit4:junit4] 2> 216276 T667 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 216278 T667 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 216278 T667 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 216282 T667 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1371313535869\collection1\'
[junit4:junit4] 2> 216285 T667 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1371313535869/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 216287 T667 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1371313535869/collection1/lib/README' to classloader
[junit4:junit4] 2> 216371 T667 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 216461 T667 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 216464 T667 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 216470 T667 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 217305 T667 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 217318 T667 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 217323 T667 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 217346 T667 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 217352 T667 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 217357 T667 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 217359 T667 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 217360 T667 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 217360 T667 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 217361 T667 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 217362 T667 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 217362 T667 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 217362 T667 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1371313535869\collection1\, dataDir=.\org.apache.solr.cloud.RecoveryZkTest-1371313535638/control/data\
[junit4:junit4] 2> 217362 T667 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@a45536
[junit4:junit4] 2> 217363 T667 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 217364 T667 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.RecoveryZkTest-1371313535638/control/data\
[junit4:junit4] 2> 217364 T667 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.RecoveryZkTest-1371313535638/control/data\index/
[junit4:junit4] 2> 217364 T667 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.RecoveryZkTest-1371313535638\control\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 217365 T667 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.RecoveryZkTest-1371313535638/control/data\index
[junit4:junit4] 2> 217370 T667 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@17f0e53 lockFactory=org.apache.lucene.store.NativeFSLockFactory@17fe015),segFN=segments_1,generation=1}
[junit4:junit4] 2> 217370 T667 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 217373 T667 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 217373 T667 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 217374 T667 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 217375 T667 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 217375 T667 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 217375 T667 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 217376 T667 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 217376 T667 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 217377 T667 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 217385 T667 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 217393 T667 oass.SolrIndexSearcher.<init> Opening Searcher@14dcba main
[junit4:junit4] 2> 217393 T667 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.RecoveryZkTest-1371313535638\control\data\tlog
[junit4:junit4] 2> 217395 T667 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 217395 T667 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 217399 T668 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@14dcba main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 217400 T667 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 217400 T667 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:63391/we_j/g collection:control_collection shard:shard1
[junit4:junit4] 2> 217402 T667 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 217422 T667 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 217427 T667 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 217427 T667 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 217427 T667 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:63391/we_j/g/collection1/
[junit4:junit4] 2> 217428 T667 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 217428 T667 oasc.SyncStrategy.syncToMe http://127.0.0.1:63391/we_j/g/collection1/ has no replicas
[junit4:junit4] 2> 217428 T667 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:63391/we_j/g/collection1/
[junit4:junit4] 2> 217428 T667 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 218800 T665 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 218817 T664 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> 218867 T667 oasc.ZkController.register We are http://127.0.0.1:63391/we_j/g/collection1/ and leader is http://127.0.0.1:63391/we_j/g/collection1/
[junit4:junit4] 2> 218867 T667 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:63391/we_j/g
[junit4:junit4] 2> 218867 T667 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 218868 T667 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 218868 T667 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 218871 T667 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 218873 T642 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 218873 T642 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 218874 T642 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 218883 T642 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 218885 T642 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 218889 T671 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@d3ac67 name:ZooKeeperConnection Watcher:127.0.0.1:63384/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 218890 T642 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 218892 T642 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 218897 T642 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 219352 T642 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 219355 T642 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:63403
[junit4:junit4] 2> 219356 T642 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 219356 T642 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 219357 T642 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1371313541220
[junit4:junit4] 2> 219357 T642 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1371313541220\solr.xml
[junit4:junit4] 2> 219357 T642 oasc.CoreContainer.<init> New CoreContainer 28346166
[junit4:junit4] 2> 219357 T642 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1371313541220\'
[junit4:junit4] 2> 219357 T642 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1371313541220\'
[junit4:junit4] 2> 219479 T642 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 219479 T642 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 219479 T642 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 219480 T642 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 219480 T642 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 219480 T642 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 219481 T642 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 219481 T642 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 219482 T642 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 219482 T642 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 219490 T642 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 219490 T642 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:63384/solr
[junit4:junit4] 2> 219491 T642 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 219492 T642 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 219509 T682 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6d61cf name:ZooKeeperConnection Watcher:127.0.0.1:63384 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 219510 T642 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 219513 T642 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 219519 T642 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 219523 T684 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@10a861a name:ZooKeeperConnection Watcher:127.0.0.1:63384/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 219524 T642 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 219531 T642 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 220326 T665 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 220328 T665 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:63391_we_j%2Fg",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63391/we_j/g"}
[junit4:junit4] 2> 220343 T671 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> 220343 T664 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> 220343 T684 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> 220535 T642 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63403_we_j%2Fg
[junit4:junit4] 2> 220538 T642 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:63403_we_j%2Fg
[junit4:junit4] 2> 220544 T671 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> 220546 T684 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 220546 T684 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> 220546 T664 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 220547 T664 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> 220550 T671 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 220561 T685 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 220562 T685 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 221857 T665 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 221857 T665 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:63403_we_j%2Fg",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63403/we_j/g"}
[junit4:junit4] 2> 221857 T665 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 1
[junit4:junit4] 2> 221858 T665 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 221872 T671 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> 221872 T684 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> 221872 T664 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> 222564 T685 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1371313541220\collection1
[junit4:junit4] 2> 222564 T685 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 222565 T685 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 222565 T685 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 222568 T685 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1371313541220\collection1\'
[junit4:junit4] 2> 222569 T685 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1371313541220/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 222570 T685 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1371313541220/collection1/lib/README' to classloader
[junit4:junit4] 2> 222649 T685 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 222734 T685 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 222737 T685 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 222744 T685 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 223561 T685 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 223574 T685 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 223582 T685 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 223605 T685 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 223610 T685 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 223616 T685 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 223618 T685 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 223619 T685 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 223619 T685 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 223621 T685 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 223621 T685 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 223621 T685 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 223622 T685 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1371313541220\collection1\, dataDir=.\org.apache.solr.cloud.RecoveryZkTest-1371313535638/jetty1\
[junit4:junit4] 2> 223622 T685 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@a45536
[junit4:junit4] 2> 223623 T685 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 223623 T685 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.RecoveryZkTest-1371313535638/jetty1\
[junit4:junit4] 2> 223623 T685 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.RecoveryZkTest-1371313535638/jetty1\index/
[junit4:junit4] 2> 223624 T685 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.RecoveryZkTest-1371313535638\jetty1\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 223624 T685 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.RecoveryZkTest-1371313535638/jetty1\index
[junit4:junit4] 2> 223628 T685 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@f37bb8 lockFactory=org.apache.lucene.store.NativeFSLockFactory@ada913),segFN=segments_1,generation=1}
[junit4:junit4] 2> 223629 T685 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 223633 T685 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 223633 T685 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 223633 T685 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 223634 T685 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 223635 T685 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 223635 T685 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 223636 T685 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 223636 T685 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 223637 T685 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 223645 T685 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 223652 T685 oass.SolrIndexSearcher.<init> Opening Searcher@48a4ad main
[junit4:junit4] 2> 223652 T685 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.RecoveryZkTest-1371313535638\jetty1\tlog
[junit4:junit4] 2> 223654 T685 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 223654 T685 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 223661 T686 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@48a4ad main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 223663 T685 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 223664 T685 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:63403/we_j/g collection:collection1 shard:shard1
[junit4:junit4] 2> 223665 T685 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 223687 T685 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 223692 T685 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 223692 T685 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 223692 T685 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:63403/we_j/g/collection1/
[junit4:junit4] 2> 223692 T685 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 223693 T685 oasc.SyncStrategy.syncToMe http://127.0.0.1:63403/we_j/g/collection1/ has no replicas
[junit4:junit4] 2> 223693 T685 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:63403/we_j/g/collection1/
[junit4:junit4] 2> 223693 T685 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 224885 T665 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 224903 T671 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> 224904 T684 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> 224904 T664 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> 224925 T685 oasc.ZkController.register We are http://127.0.0.1:63403/we_j/g/collection1/ and leader is http://127.0.0.1:63403/we_j/g/collection1/
[junit4:junit4] 2> 224925 T685 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:63403/we_j/g
[junit4:junit4] 2> 224925 T685 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 224925 T685 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 224925 T685 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 224929 T685 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 224930 T642 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 224930 T642 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 224931 T642 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 225388 T642 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 225554 T3 oasc.CoreContainer.finalize ERROR CoreContainer was not shutdown prior to finalize(), indicates a bug -- POSSIBLE RESOURCE LEAK!!! instance=29694502
[junit4:junit4] 2> 225555 T3 oasc.CoreContainer.finalize ERROR CoreContainer was not shutdown prior to finalize(), indicates a bug -- POSSIBLE RESOURCE LEAK!!! instance=10914320
[junit4:junit4] 2> 225555 T642 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:63412
[junit4:junit4] 2> 225555 T3 oasc.CoreContainer.finalize ERROR CoreContainer was not shutdown prior to finalize(), indicates a bug -- POSSIBLE RESOURCE LEAK!!! instance=27674873
[junit4:junit4] 2> 225557 T642 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 225557 T642 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 225557 T642 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1371313547261
[junit4:junit4] 2> 225557 T642 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1371313547261\solr.xml
[junit4:junit4] 2> 225558 T642 oasc.CoreContainer.<init> New CoreContainer 15366242
[junit4:junit4] 2> 225558 T642 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1371313547261\'
[junit4:junit4] 2> 225558 T642 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1371313547261\'
[junit4:junit4] 2> 225687 T642 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 225687 T642 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 225688 T642 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 225688 T642 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 225689 T642 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 225689 T642 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 225690 T642 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 225690 T642 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 225690 T642 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 225690 T642 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 225698 T642 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 225698 T642 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:63384/solr
[junit4:junit4] 2> 225699 T642 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 225701 T642 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 225718 T698 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@15aa488 name:ZooKeeperConnection Watcher:127.0.0.1:63384 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 225719 T642 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 225723 T642 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 225723 T644 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13f48a7faa00007, 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:662)
[junit4:junit4] 2>
[junit4:junit4] 2> 225729 T642 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 225733 T700 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1161136 name:ZooKeeperConnection Watcher:127.0.0.1:63384/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 225733 T642 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 225741 T642 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 226415 T665 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 226416 T665 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:63403_we_j%2Fg",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63403/we_j/g"}
[junit4:junit4] 2> 226427 T671 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> 226428 T684 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> 226429 T700 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> 226428 T664 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> 226746 T642 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:63412_we_j%2Fg
[junit4:junit4] 2> 226749 T642 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:63412_we_j%2Fg
[junit4:junit4] 2> 226754 T671 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> 226755 T684 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 226756 T684 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> 226757 T664 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 226757 T664 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> 226757 T700 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 226758 T700 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> 226763 T671 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 226772 T701 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 226773 T701 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 227940 T665 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 227940 T665 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:63412_we_j%2Fg",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63412/we_j/g"}
[junit4:junit4] 2> 227940 T665 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4] 2> 227941 T665 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 227954 T664 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> 227954 T684 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> 227955 T671 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> 227955 T700 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> 228775 T701 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1371313547261\collection1
[junit4:junit4] 2> 228775 T701 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 228776 T701 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 228777 T701 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 228780 T701 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1371313547261\collection1\'
[junit4:junit4] 2> 228781 T701 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1371313547261/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 228782 T701 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-4.x-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1371313547261/collection1/lib/README' to classloader
[junit4:junit4] 2> 228848 T701 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 228930 T701 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 228932 T701 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 228939 T701 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 229757 T701 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 229770 T701 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 229774 T701 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 229798 T701 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 229804 T701 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 229811 T701 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 229813 T701 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 229813 T701 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 229814 T701 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 229815 T701 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 229815 T701 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 229815 T701 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 229816 T701 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1371313547261\collection1\, dataDir=.\org.apache.solr.cloud.RecoveryZkTest-1371313535638/jetty2\
[junit4:junit4] 2> 229816 T701 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@a45536
[junit4:junit4] 2> 229816 T701 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 229817 T701 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.RecoveryZkTest-1371313535638/jetty2\
[junit4:junit4] 2> 229818 T701 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.RecoveryZkTest-1371313535638/jetty2\index/
[junit4:junit4] 2> 229818 T701 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.RecoveryZkTest-1371313535638\jetty2\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 229818 T701 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.RecoveryZkTest-1371313535638/jetty2\index
[junit4:junit4] 2> 229823 T701 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1694399 lockFactory=org.apache.lucene.store.NativeFSLockFactory@a490d4),segFN=segments_1,generation=1}
[junit4:junit4] 2> 229823 T701 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 229827 T701 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 229827 T701 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 229828 T701 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 229829 T701 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 229829 T701 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 229829 T701 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 229829 T701 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 229831 T701 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 229831 T701 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 229840 T701 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 229848 T701 oass.SolrIndexSearcher.<init> Opening Searcher@18b30f3 main
[junit4:junit4] 2> 229849 T701 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.RecoveryZkTest-1371313535638\jetty2\tlog
[junit4:junit4] 2> 229850 T701 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 229851 T701 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 229857 T702 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@18b30f3 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 229860 T701 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 229861 T701 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:63412/we_j/g collection:collection1 shard:shard1
[junit4:junit4] 2> 229874 T701 oasc.ZkController.register We are http://127.0.0.1:63412/we_j/g/collection1/ and leader is http://127.0.0.1:63403/we_j/g/collection1/
[junit4:junit4] 2> 229875 T701 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:63412/we_j/g
[junit4:junit4] 2> 229875 T701 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 229875 T701 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C496 name=collection1 org.apache.solr.core.SolrCore@a920ad url=http://127.0.0.1:63412/we_j/g/collection1 node=127.0.0.1:63412_we_j%2Fg C496_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:63412_we_j%2Fg, base_url=http://127.0.0.1:63412/we_j/g}
[junit4:junit4] 2> 229876 T703 C496 P63412 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 229877 T703 C496 P63412 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 229877 T703 C496 P63412 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 229878 T703 C496 P63412 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 229877 T701 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 229880 T703 C496 P63412 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 229883 T642 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 229883 T642 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 229883 T642 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 229896 T642 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 229899 T679 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 3, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> ASYNC NEW_CORE C497 name=collection1 org.apache.solr.core.SolrCore@4fa1cd url=http://127.0.0.1:63391/we_j/g/collection1 node=127.0.0.1:63391_we_j%2Fg C497_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:63391_we_j%2Fg, base_url=http://127.0.0.1:63391/we_j/g, leader=true}
[junit4:junit4] 2> 229926 T656 C497 P63391 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@17f0e53 lockFactory=org.apache.lucene.store.NativeFSLockFactory@17fe015),segFN=segments_1,generation=1}
[junit4:junit4] 2> 229926 T656 C497 P63391 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 229932 T656 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10001 (1437926479359901696)]} 0 9
[junit4:junit4] 2> 229932 T655 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[1 (1437926479359901697)]} 0 9
[junit4:junit4] 2> ASYNC NEW_CORE C498 name=collection1 org.apache.solr.core.SolrCore@826a5f url=http://127.0.0.1:63403/we_j/g/collection1 node=127.0.0.1:63403_we_j%2Fg C498_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:63403_we_j%2Fg, base_url=http://127.0.0.1:63403/we_j/g, leader=true}
[junit4:junit4] 2> 229958 T680 C498 P63403 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@f37bb8 lockFactory=org.apache.lucene.store.NativeFSLockFactory@ada913),segFN=segments_1,generation=1}
[junit4:junit4] 2> 229958 T680 C498 P63403 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 229964 T673 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[1 (1437926479393456128)]} 0 9
[junit4:junit4] 2> 229964 T680 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10001 (1437926479393456129)]} 0 10
[junit4:junit4] 2> 229981 T657 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10002 (1437926479419670528)]} 0 1
[junit4:junit4] 2> 229983 T658 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[2 (1437926479419670529)]} 0 3
[junit4:junit4] 2> 229988 T676 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10002 (1437926479427010560)]} 0 2
[junit4:junit4] 2> 229988 T677 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[2 (1437926479427010561)]} 0 2
[junit4:junit4] 2> 230083 T656 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10002 (-1437926479526625281)]} 0 1
[junit4:junit4] 2> 230083 T659 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[2 (-1437926479526625280)]} 0 1
[junit4:junit4] 2> 230087 T678 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10002 (-1437926479531868160)]} 0 0
[junit4:junit4] 2> 230091 T673 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[2 (-1437926479535013888)]} 0 2
[junit4:junit4] 2> 230094 T655 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10003 (1437926479538159616)]} 0 1
[junit4:junit4] 2> 230096 T657 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[3 (1437926479539208192)]} 0 2
[junit4:junit4] 2> 230100 T680 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10003 (1437926479543402496)]} 0 2
[junit4:junit4] 2> 230101 T676 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[3 (1437926479545499648)]} 0 1
[junit4:junit4] 2> 230150 T658 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10003 (-1437926479597928448)]} 0 0
[junit4:junit4] 2> 230151 T660 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[3 (-1437926479598977024)]} 0 0
[junit4:junit4] 2> 230153 T677 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10003 (-1437926479601074176)]} 0 0
[junit4:junit4] 2> 230154 T678 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[3 (-1437926479602122752)]} 0 0
[junit4:junit4] 2> 230157 T656 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10004 (1437926479604219904)]} 0 1
[junit4:junit4] 2> 230158 T659 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[4 (1437926479605268480)]} 0 1
[junit4:junit4] 2> 230159 T673 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10004 (1437926479607365632)]} 0 0
[junit4:junit4] 2> 230162 T680 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[4 (1437926479609462784)]} 0 1
[junit4:junit4] 2> 230186 T655 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10005 (1437926479634628608)]} 0 1
[junit4:junit4] 2> 230189 T676 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10005 (1437926479637774336)]} 0 1
[junit4:junit4] 2> 230189 T657 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[5 (1437926479637774336)]} 0 1
[junit4:junit4] 2> 230192 T678 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[5 (1437926479640920064)]} 0 1
[junit4:junit4] 2> 230196 T658 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10004 (-1437926479646162944)]} 0 0
[junit4:junit4] 2> 230200 T673 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10004 (-1437926479650357248)]} 0 0
[junit4:junit4] 2> 230201 T660 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[4 (-1437926479651405824)]} 0 0
[junit4:junit4] 2> 230203 T656 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10006 (1437926479653502976)]} 0 0
[junit4:junit4] 2> 230204 T680 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[4 (-1437926479654551552)]} 0 0
[junit4:junit4] 2> 230206 T677 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10006 (1437926479656648704)]} 0 0
[junit4:junit4] 2> 230208 T659 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[6 (1437926479657697280)]} 0 1
[junit4:junit4] 2> 230212 T676 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[6 (1437926479661891584)]} 0 1
[junit4:junit4] 2> 230223 T655 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10007 (1437926479673425920)]} 0 1
[junit4:junit4] 2> 230227 T678 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10007 (1437926479677620224)]} 0 1
[junit4:junit4] 2> 230229 T657 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[7 (1437926479680765952)]} 0 0
[junit4:junit4] 2> 230232 T673 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[7 (1437926479683911680)]} 0 0
[junit4:junit4] 2> 230233 T658 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10008 (1437926479683911680)]} 0 1
[junit4:junit4] 2> 230237 T660 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[8 (1437926479688105984)]} 0 1
[junit4:junit4] 2> 230237 T680 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10008 (1437926479688105984)]} 0 1
[junit4:junit4] 2> 230241 T677 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[8 (1437926479692300288)]} 0 1
[junit4:junit4] 2> 230273 T656 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10008 (-1437926479725854720)]} 0 1
[junit4:junit4] 2> 230274 T659 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[8 (-1437926479727951872)]} 0 0
[junit4:junit4] 2> 230275 T676 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10008 (-1437926479729000448)]} 0 0
[junit4:junit4] 2> 230276 T676 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[8 (-1437926479730049024)]} 0 0
[junit4:junit4] 2> 230280 T655 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10009 (1437926479732146176)]} 0 2
[junit4:junit4] 2> 230280 T657 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[9 (1437926479734243328)]} 0 0
[junit4:junit4] 2> 230289 T680 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10009 (1437926479737389056)]} 0 6
[junit4:junit4] 2> 230291 T673 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[9 (1437926479737389057)]} 0 8
[junit4:junit4] 2> 230300 T658 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10010 (1437926479754166272)]} 0 1
[junit4:junit4] 2> 230302 T660 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10 (1437926479755214848)]} 0 2
[junit4:junit4] 2> 230306 T677 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10010 (1437926479760457728)]} 0 1
[junit4:junit4] 2> 230308 T678 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10 (1437926479763603456)]} 0 0
[junit4:junit4] 2> 230372 T656 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10011 (1437926479829663744)]} 0 2
[junit4:junit4] 2> 230375 T676 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10011 (1437926479833858048)]} 0 0
[junit4:junit4] 2> 230375 T659 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[11 (1437926479833858048)]} 0 1
[junit4:junit4] 2> 230381 T680 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[11 (1437926479839100928)]} 0 1
[junit4:junit4] 2> 230420 T655 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10012 (1437926479879995392)]} 0 1
[junit4:junit4] 2> 230423 T673 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10012 (1437926479884189696)]} 0 0
[junit4:junit4] 2> 230426 T657 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[12 (1437926479886286848)]} 0 1
[junit4:junit4] 2> 230429 T677 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[12 (1437926479889432576)]} 0 1
[junit4:junit4] 2> 230473 T658 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10009 (-1437926479936618496)]} 0 0
[junit4:junit4] 2> 230476 T678 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10009 (-1437926479939764224)]} 0 0
[junit4:junit4] 2> 230478 T660 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[9 (-1437926479941861376)]} 0 0
[junit4:junit4] 2> 230480 T656 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10013 (1437926479942909952)]} 0 1
[junit4:junit4] 2> 230481 T676 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[9 (-1437926479945007104)]} 0 0
[junit4:junit4] 2> 230482 T680 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10013 (1437926479946055680)]} 0 0
[junit4:junit4] 2> 230484 T659 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[13 (1437926479948152832)]} 0 0
[junit4:junit4] 2> 230488 T673 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[13 (1437926479951298560)]} 0 1
[junit4:junit4] 2> 230501 T657 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10010 (-1437926479965978624)]} 0 0
[junit4:junit4] 2> 230504 T677 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10010 (-1437926479969124352)]} 0 0
[junit4:junit4] 2> 230505 T658 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10 (-1437926479970172928)]} 0 0
[junit4:junit4] 2> 230509 T660 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10014 (1437926479972270080)]} 0 2
[junit4:junit4] 2> 230509 T678 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10 (-1437926479974367232)]} 0 0
[junit4:junit4] 2> 230512 T676 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10014 (1437926479976464384)]} 0 1
[junit4:junit4] 2> 230513 T656 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[14 (1437926479977512960)]} 0 1
[junit4:junit4] 2> 230517 T680 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[14 (1437926479981707264)]} 0 1
[junit4:junit4] 2> 230559 T655 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10012 (-1437926480026796032)]} 0 0
[junit4:junit4] 2> 230562 T673 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10012 (-1437926480029941760)]} 0 0
[junit4:junit4] 2> 230564 T659 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[12 (-1437926480032038912)]} 0 1
[junit4:junit4] 2> 230565 T677 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[12 (-1437926480033087488)]} 0 0
[junit4:junit4] 2> 230567 T657 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10015 (1437926480033087488)]} 0 2
[junit4:junit4] 2> 230570 T658 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[15 (1437926480037281792)]} 0 1
[junit4:junit4] 2> 230571 T678 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10015 (1437926480038330368)]} 0 1
[junit4:junit4] 2> 230574 T676 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[15 (1437926480041476096)]} 0 1
[junit4:junit4] 2> 230644 T660 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10016 (1437926480114876416)]} 0 1
[junit4:junit4] 2> 230648 T656 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[16 (1437926480118022144)]} 0 2
[junit4:junit4] 2> 230649 T680 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10016 (1437926480120119296)]} 0 1
[junit4:junit4] 2> 230651 T677 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[16 (1437926480122216448)]} 0 1
[junit4:junit4] 2> 230722 T655 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10016 (-1437926480197713920)]} 0 0
[junit4:junit4] 2> 230725 T659 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[16 (-1437926480200859648)]} 0 0
[junit4:junit4] 2> 230725 T678 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10016 (-1437926480200859648)]} 0 0
[junit4:junit4] 2> 230728 T676 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[16 (-1437926480204005376)]} 0 0
[junit4:junit4] 2> 230730 T657 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10017 (1437926480205053952)]} 0 1
[junit4:junit4] 2> 230731 T658 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[17 (1437926480207151104)]} 0 0
[junit4:junit4] 2> 230733 T673 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10017 (1437926480209248256)]} 0 1
[junit4:junit4] 2> 230734 T680 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[17 (1437926480210296832)]} 0 0
[junit4:junit4] 2> 230783 T660 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10017 (-1437926480261677056)]} 0 0
[junit4:junit4] 2> 230785 T656 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[17 (-1437926480263774208)]} 0 0
[junit4:junit4] 2> 230787 T677 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10017 (-1437926480265871360)]} 0 0
[junit4:junit4] 2> 230788 T677 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[17 (-1437926480266919936)]} 0 0
[junit4:junit4] 2> 230791 T655 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10018 (1437926480269017088)]} 0 1
[junit4:junit4] 2> 230792 T659 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[18 (1437926480270065664)]} 0 1
[junit4:junit4] 2> 230794 T676 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10018 (1437926480273211392)]} 0 0
[junit4:junit4] 2> 230797 T673 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[18 (1437926480275308544)]} 0 1
[junit4:junit4] 2> 230813 T657 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10019 (1437926480292085760)]} 0 1
[junit4:junit4] 2> 230815 T658 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[19 (1437926480294182912)]} 0 1
[junit4:junit4] 2> 230816 T680 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10019 (1437926480295231488)]} 0 1
[junit4:junit4] 2> 230818 T678 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[19 (1437926480297328640)]} 0 1
[junit4:junit4] 2> 230863 T660 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10020 (1437926480343465984)]} 0 2
[junit4:junit4] 2> 230863 T656 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[20 (1437926480345563136)]} 0 0
[junit4:junit4] 2> 230867 T677 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10020 (1437926480348708864)]} 0 1
[junit4:junit4] 2> 230868 T676 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[20 (1437926480350806016)]} 0 1
[junit4:junit4] 2> 230959 T655 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10019 (-1437926480446226432)]} 0 0
[junit4:junit4] 2> 230960 T657 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[19 (-1437926480447275008)]} 0 0
[junit4:junit4] 2> 230962 T673 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10019 (-1437926480449372160)]} 0 0
[junit4:junit4] 2> 230964 T680 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[19 (-1437926480451469312)]} 0 0
[junit4:junit4] 2> 230966 T658 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10021 (1437926480452517888)]} 0 1
[junit4:junit4] 2> 230968 T656 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[21 (1437926480454615040)]} 0 1
[junit4:junit4] 2> 230971 T678 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10021 (1437926480457760768)]} 0 1
[junit4:junit4] 2> 230973 T677 C498 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[21 (1437926480459857920)]} 0 1
[junit4:junit4] 2> 230973 T665 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 230975 T665 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:63412_we_j%2Fg",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63412/we_j/g"}
[junit4:junit4] 2> 230985 T664 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> 230986 T684 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> 230986 T700 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> 230986 T671 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> 231005 T660 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10022 (1437926480492363776)]} 0 2
[junit4:junit4] 2> 231006 T659 C497 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[22 (1437926480494460928)]} 0 1
[junit4:junit4] 2> ASYNC NEW_CORE C499 name=collection1 org.apache.solr.core.SolrCore@a920ad url=http://127.0.0.1:63412/we_j/g/collection1 node=127.0.0.1:63412_we_j%2Fg C499_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:63412_we_j%2Fg, base_url=http://127.0.0.1:63412/we_j/g}
[junit4:junit4] 2> 231035 T694 C499 P63412 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1694399 lockFactory=org.apache.lucene.store.NativeFSLockFactory@a490d4),segFN=segments_1,generation=1}
[junit4:junit4] 2> 231037 T694 C499 P63412 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 231044 T694 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10022 (1437926480497606656)]} 0 13
[junit4:junit4] 2> 231044 T696 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[22 (1437926480498655232)]} 0 7
[junit4:junit4] 2> ASYNC NEW_CORE C500 name=collection1 org.apache.solr.core.SolrCore@826a5f url=http://127.0.0.1:63403/we_j/g/collection1 node=127.0.0.1:63403_we_j%2Fg C500_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:63403_we_j%2Fg, base_url=http://127.0.0.1:63403/we_j/g, leader=true}
[junit4:junit4] 2> 231045 T673 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[22 (1437926480498655232)]} 0 36
[junit4:junit4] 2> 231045 T676 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10022 (1437926480497606656)]} 0 37
[junit4:junit4] 2> ASYNC NEW_CORE C501 name=collection1 org.apache.solr.core.SolrCore@4fa1cd url=http://127.0.0.1:63391/we_j/g/collection1 node=127.0.0.1:63391_we_j%2Fg C501_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:63391_we_j%2Fg, base_url=http://127.0.0.1:63391/we_j/g, leader=true}
[junit4:junit4] 2> 231050 T657 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[20 (-1437926480541646848)]} 0 0
[junit4:junit4] 2> 231050 T655 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10020 (-1437926480541646849)]} 0 0
[junit4:junit4] 2> 231058 T690 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[20 (-1437926480545841152)]} 0 1
[junit4:junit4] 2> 231060 T680 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[20 (-1437926480545841152)]} 0 6
[junit4:junit4] 2> 231061 T691 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10020 (-1437926480546889728)]} 0 2
[junit4:junit4] 2> 231062 T677 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10020 (-1437926480546889728)]} 0 7
[junit4:junit4] 2> 231065 T656 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10023 (1437926480556326913)]} 0 1
[junit4:junit4] 2> 231065 T658 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[23 (1437926480556326912)]} 0 1
[junit4:junit4] 2> 231075 T692 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10023 (1437926480559472640)]} 0 4
[junit4:junit4] 2> 231075 T693 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[23 (1437926480561569792)]} 0 3
[junit4:junit4] 2> 231076 T673 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10023 (1437926480559472640)]} 0 9
[junit4:junit4] 2> 231077 T676 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[23 (1437926480561569792)]} 0 8
[junit4:junit4] 2> 231133 T660 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[24 (1437926480627630080)]} 0 1
[junit4:junit4] 2> 231140 T659 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10024 (1437926480627630081)]} 0 8
[junit4:junit4] 2> 231144 T696 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[24 (1437926480633921536)]} 0 1
[junit4:junit4] 2> 231145 T678 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[24 (1437926480633921536)]} 0 7
[junit4:junit4] 2> 231148 T694 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10024 (1437926480639164416)]} 0 1
[junit4:junit4] 2> 231149 T680 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10024 (1437926480639164416)]} 0 6
[junit4:junit4] 2> 231225 T657 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[25 (1437926480724099072)]} 0 1
[junit4:junit4] 2> 231230 T655 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10025 (1437926480729341952)]} 0 1
[junit4:junit4] 2> 231236 T690 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[25 (1437926480732487680)]} 0 2
[junit4:junit4] 2> 231237 T677 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[25 (1437926480732487680)]} 0 5
[junit4:junit4] 2> 231238 T692 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10025 (1437926480734584832)]} 0 0
[junit4:junit4] 2> 231239 T673 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10025 (1437926480734584832)]} 0 5
[junit4:junit4] 2> 231262 T656 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[23 (-1437926480763944960)]} 0 0
[junit4:junit4] 2> 231263 T658 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10023 (-1437926480764993536)]} 0 0
[junit4:junit4] 2> 231267 T693 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[23 (-1437926480767090688)]} 0 0
[junit4:junit4] 2> 231268 T696 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10023 (-1437926480768139264)]} 0 0
[junit4:junit4] 2> 231268 T676 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[23 (-1437926480767090688)]} 0 3
[junit4:junit4] 2> 231269 T678 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10023 (-1437926480768139264)]} 0 3
[junit4:junit4] 2> 231274 T659 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[26 (1437926480775479296)]} 0 1
[junit4:junit4] 2> 231274 T660 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10026 (1437926480775479297)]} 0 1
[junit4:junit4] 2> 231280 T694 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[26 (1437926480778625025)]} 0 1
[junit4:junit4] 2> 231281 T680 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[26 (1437926480778625025)]} 0 5
[junit4:junit4] 2> 231281 T691 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10026 (1437926480778625024)]} 0 1
[junit4:junit4] 2> 231283 T677 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10026 (1437926480778625024)]} 0 7
[junit4:junit4] 2> 231359 T657 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[27 (1437926480863559680)]} 0 2
[junit4:junit4] 2> 231360 T655 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10027 (1437926480865656832)]} 0 1
[junit4:junit4] 2> 231365 T690 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[27 (1437926480868802560)]} 0 0
[junit4:junit4] 2> 231367 T673 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[27 (1437926480868802560)]} 0 5
[junit4:junit4] 2> 231368 T692 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10027 (1437926480869851136)]} 0 1
[junit4:junit4] 2> 231369 T676 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10027 (1437926480869851136)]} 0 6
[junit4:junit4] 2> 231382 T658 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[24 (-1437926480889774080)]} 0 0
[junit4:junit4] 2> 231383 T660 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10024 (-1437926480890822656)]} 0 0
[junit4:junit4] 2> 231387 T693 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[24 (-1437926480892919808)]} 0 0
[junit4:junit4] 2> 231388 T678 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[24 (-1437926480892919808)]} 0 3
[junit4:junit4] 2> 231389 T696 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10024 (-1437926480893968384)]} 0 0
[junit4:junit4] 2> 231390 T680 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10024 (-1437926480893968384)]} 0 4
[junit4:junit4] 2> 231393 T659 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[28 (1437926480899211264)]} 0 2
[junit4:junit4] 2> 231396 T659 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10028 (1437926480903405568)]} 0 2
[junit4:junit4] 2> 231399 T694 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[28 (1437926480904454144)]} 0 0
[junit4:junit4] 2> 231400 T677 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[28 (1437926480904454144)]} 0 4
[junit4:junit4] 2> 231404 T691 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10028 (1437926480907599872)]} 0 1
[junit4:junit4] 2> 231405 T673 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10028 (1437926480907599872)]} 0 6
[junit4:junit4] 2> 231452 T656 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[29 (1437926480962125824)]} 0 1
[junit4:junit4] 2> 231457 T655 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10029 (1437926480967368704)]} 0 1
[junit4:junit4] 2> 231460 T690 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[29 (1437926480967368704)]} 0 1
[junit4:junit4] 2> 231461 T676 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[29 (1437926480967368704)]} 0 5
[junit4:junit4] 2> 231464 T692 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10029 (1437926480971563008)]} 0 1
[junit4:junit4] 2> 231465 T680 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10029 (1437926480971563008)]} 0 5
[junit4:junit4] 2> 231519 T658 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[25 (-1437926481033428992)]} 0 0
[junit4:junit4] 2> 231522 T660 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10025 (-1437926481036574720)]} 0 0
[junit4:junit4] 2> 231524 T693 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[25 (-1437926481036574720)]} 0 0
[junit4:junit4] 2> 231524 T677 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[25 (-1437926481036574720)]} 0 2
[junit4:junit4] 2> 231526 T657 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[30 (1437926481040769024)]} 0 0
[junit4:junit4] 2> 231527 T696 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10025 (-1437926481039720448)]} 0 0
[junit4:junit4] 2> 231528 T673 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10025 (-1437926481039720448)]} 0 3
[junit4:junit4] 2> 231530 T659 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10030 (1437926481044963328)]} 0 0
[junit4:junit4] 2> 231533 T694 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[30 (1437926481043914752)]} 0 1
[junit4:junit4] 2> 231537 T678 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[30 (1437926481043914752)]} 0 8
[junit4:junit4] 2> 231539 T694 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10030 (1437926481048109056)]} 0 3
[junit4:junit4] 2> 231540 T676 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10030 (1437926481048109056)]} 0 7
[junit4:junit4] 2> 231599 T656 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[26 (-1437926481117315072)]} 0 0
[junit4:junit4] 2> 231600 T655 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10026 (-1437926481118363648)]} 0 0
[junit4:junit4] 2> 231604 T690 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[26 (-1437926481120460800)]} 0 0
[junit4:junit4] 2> 231605 T680 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[26 (-1437926481120460800)]} 0 3
[junit4:junit4] 2> 231605 T690 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10026 (-1437926481121509376)]} 0 0
[junit4:junit4] 2> 231606 T677 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10026 (-1437926481121509376)]} 0 3
[junit4:junit4] 2> 231607 T658 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[31 (1437926481125703680)]} 0 0
[junit4:junit4] 2> 231608 T658 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10031 (1437926481126752256)]} 0 0
[junit4:junit4] 2> 231616 T696 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10031 (1437926481131995136)]} 0 0
[junit4:junit4] 2> 231617 T678 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10031 (1437926481131995136)]} 0 4
[junit4:junit4] 2> 231620 T693 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[31 (1437926481130946560)]} 0 0
[junit4:junit4] 2> 231621 T673 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[31 (1437926481130946560)]} 0 9
[junit4:junit4] 2> 231660 T657 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10032 (1437926481180229632)]} 0 1
[junit4:junit4] 2> 231663 T659 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[32 (1437926481183375360)]} 0 1
[junit4:junit4] 2> 231671 T691 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10032 (1437926481186521088)]} 0 1
[junit4:junit4] 2> 231672 T676 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10032 (1437926481186521088)]} 0 7
[junit4:junit4] 2> 231674 T692 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[32 (1437926481191763968)]} 0 1
[junit4:junit4] 2> 231675 T680 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[32 (1437926481191763968)]} 0 5
[junit4:junit4] 2> 231697 T656 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10033 (1437926481217978368)]} 0 2
[junit4:junit4] 2> 231700 T655 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[33 (1437926481223221248)]} 0 0
[junit4:junit4] 2> 231705 T696 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10033 (1437926481225318400)]} 0 0
[junit4:junit4] 2> 231707 T690 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[33 (1437926481226366976)]} 0 2
[junit4:junit4] 2> 231709 T677 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10033 (1437926481225318400)]} 0 7
[junit4:junit4] 2> 231710 T678 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[33 (1437926481226366976)]} 0 7
[junit4:junit4] 2> 231795 T658 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10027 (-1437926481322835968)]} 0 0
[junit4:junit4] 2> 231797 T657 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[27 (-1437926481324933120)]} 0 0
[junit4:junit4] 2> 231802 T694 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[27 (-1437926481328078848)]} 0 0
[junit4:junit4] 2> 231802 T693 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10027 (-1437926481327030272)]} 0 0
[junit4:junit4] 2> 231804 T676 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[27 (-1437926481328078848)]} 0 4
[junit4:junit4] 2> 231804 T673 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10027 (-1437926481327030272)]} 0 5
[junit4:junit4] 2> 231807 T659 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[34 (1437926481334370304)]} 0 1
[junit4:junit4] 2> 231807 T656 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10034 (1437926481335418880)]} 0 0
[junit4:junit4] 2> 231815 T691 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10034 (1437926481339613185)]} 0 1
[junit4:junit4] 2> 231815 T692 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[34 (1437926481339613184)]} 0 1
[junit4:junit4] 2> 231815 T680 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10034 (1437926481339613185)]} 0 4
[junit4:junit4] 2> 231816 T677 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[34 (1437926481339613184)]} 0 5
[junit4:junit4] 2> 231890 T655 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10029 (-1437926481422450688)]} 0 0
[junit4:junit4] 2> 231891 T660 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[29 (-1437926481423499264)]} 0 0
[junit4:junit4] 2> 231896 T690 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10029 (-1437926481426644992)]} 0 0
[junit4:junit4] 2> 231896 T696 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[29 (-1437926481426644993)]} 0 0
[junit4:junit4] 2> 231897 T676 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10029 (-1437926481426644992)]} 0 3
[junit4:junit4] 2> 231898 T678 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[29 (-1437926481426644993)]} 0 4
[junit4:junit4] 2> 231899 T679 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 3, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 231899 T679 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=3&state=recovering&nodeName=127.0.0.1:63412_we_j%252Fg&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2001
[junit4:junit4] 2> 231900 T642 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 63412
[junit4:junit4] 2> 231900 T642 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=15366242
[junit4:junit4] 2> 231900 T658 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10035 (1437926481432936448)]} 0 0
[junit4:junit4] 2> 231902 T657 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[35 (1437926481433985024)]} 0 1
[junit4:junit4] 2> 231911 T694 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10035 (1437926481438179328)]} 0 2
[junit4:junit4] 2> 231911 T693 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[35 (1437926481440276480)]} 0 0
[junit4:junit4] 2> 231912 T680 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10035 (1437926481438179328)]} 0 7
[junit4:junit4] 2> 231913 T679 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[35 (1437926481440276480)]} 0 6
[junit4:junit4] 2> 231943 T656 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10032 (-1437926481478025216)]} 0 0
[junit4:junit4] 2> 231944 T659 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[32 (-1437926481479073792)]} 0 0
[junit4:junit4] 2> 231949 T691 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[32 (-1437926481482219521)]} 0 0
[junit4:junit4] 2> 231949 T692 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10032 (-1437926481482219520)]} 0 0
[junit4:junit4] 2> 231950 T673 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[32 (-1437926481482219521)]} 0 3
[junit4:junit4] 2> 231951 T676 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10032 (-1437926481482219520)]} 0 4
[junit4:junit4] 2> 231954 T655 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[36 (1437926481488510976)]} 0 1
[junit4:junit4] 2> 231954 T660 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10036 (1437926481489559552)]} 0 0
[junit4:junit4] 2> 231962 T690 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[36 (1437926481493753856)]} 0 1
[junit4:junit4] 2> 231963 T696 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10036 (1437926481493753857)]} 0 1
[junit4:junit4] 2> 231963 T678 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[36 (1437926481493753856)]} 0 5
[junit4:junit4] 2> 231964 T677 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10036 (1437926481493753857)]} 0 6
[junit4:junit4] 2> 232052 T658 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[34 (-1437926481592320000)]} 0 0
[junit4:junit4] 2> 232053 T657 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10034 (-1437926481593368576)]} 0 0
[junit4:junit4] 2> 232057 T694 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[34 (-1437926481595465728)]} 0 0
[junit4:junit4] 2> 232058 T680 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[34 (-1437926481595465728)]} 0 3
[junit4:junit4] 2> 232059 T693 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10034 (-1437926481596514304)]} 0 0
[junit4:junit4] 2> 232060 T679 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10034 (-1437926481596514304)]} 0 4
[junit4:junit4] 2> 232062 T656 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[37 (1437926481601757184)]} 0 1
[junit4:junit4] 2> 232063 T659 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10037 (1437926481603854336)]} 0 0
[junit4:junit4] 2> 232068 T691 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[37 (1437926481605951488)]} 0 1
[junit4:junit4] 2> 232069 T673 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[37 (1437926481605951488)]} 0 4
[junit4:junit4] 2> 232070 T692 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10037 (1437926481607000064)]} 0 1
[junit4:junit4] 2> 232071 T676 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10037 (1437926481607000064)]} 0 5
[junit4:junit4] 2> 232111 T655 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[36 (-1437926481654185984)]} 0 0
[junit4:junit4] 2> 232112 T660 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10036 (-1437926481655234560)]} 0 0
[junit4:junit4] 2> 232117 T690 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[36 (-1437926481658380288)]} 0 0
[junit4:junit4] 2> 232117 T696 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10036 (-1437926481658380289)]} 0 0
[junit4:junit4] 2> 232119 T678 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[36 (-1437926481658380288)]} 0 4
[junit4:junit4] 2> 232119 T677 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10036 (-1437926481658380289)]} 0 4
[junit4:junit4] 2> 232122 T658 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[38 (1437926481664671744)]} 0 1
[junit4:junit4] 2> 232123 T657 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10038 (1437926481665720320)]} 0 1
[junit4:junit4] 2> 232128 T693 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[38 (1437926481667817472)]} 0 0
[junit4:junit4] 2> 232130 T691 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10038 (1437926481669914624)]} 0 0
[junit4:junit4] 2> 232130 T680 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[38 (1437926481667817472)]} 0 6
[junit4:junit4] 2> 232132 T679 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10038 (1437926481669914624)]} 0 6
[junit4:junit4] 2> 232229 T656 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[38 (-1437926481777917952)]} 0 0
[junit4:junit4] 2> 232230 T655 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10038 (-1437926481778966528)]} 0 0
[junit4:junit4] 2> 232233 T692 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[38 (-1437926481781063680)]} 0 0
[junit4:junit4] 2> 232234 T694 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10038 (-1437926481781063681)]} 0 0
[junit4:junit4] 2> 232235 T673 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[38 (-1437926481781063680)]} 0 3
[junit4:junit4] 2> 232235 T676 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10038 (-1437926481781063681)]} 0 3
[junit4:junit4] 2> 232239 T660 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[39 (1437926481786306560)]} 0 2
[junit4:junit4] 2> 232240 T658 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10039 (1437926481788403712)]} 0 1
[junit4:junit4] 2> 232244 T696 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[39 (1437926481790500864)]} 0 0
[junit4:junit4] 2> 232246 T678 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[39 (1437926481790500864)]} 0 4
[junit4:junit4] 2> 232247 T690 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10039 (1437926481792598016)]} 0 1
[junit4:junit4] 2> 232247 T677 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10039 (1437926481792598016)]} 0 4
[junit4:junit4] 2> 232327 T657 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[40 (1437926481879629824)]} 0 1
[junit4:junit4] 2> 232330 T659 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10040 (1437926481882775552)]} 0 1
[junit4:junit4] 2> 232336 T693 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[40 (1437926481884872704)]} 0 1
[junit4:junit4] 2> 232337 T680 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[40 (1437926481884872704)]} 0 6
[junit4:junit4] 2> 232338 T693 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10040 (1437926481886969856)]} 0 1
[junit4:junit4] 2> 232340 T673 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10040 (1437926481886969856)]} 0 7
[junit4:junit4] 2> 232401 T656 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[39 (-1437926481958273024)]} 0 1
[junit4:junit4] 2> 232406 T655 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10039 (-1437926481963515904)]} 0 0
[junit4:junit4] 2> 232410 T692 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[39 (-1437926481963515904)]} 0 0
[junit4:junit4] 2> 232412 T676 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[39 (-1437926481963515904)]} 0 6
[junit4:junit4] 2> 232413 T694 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10039 (-1437926481967710208)]} 0 0
[junit4:junit4] 2> 232415 T678 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10039 (-1437926481967710208)]} 0 5
[junit4:junit4] 2> 232416 T660 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[41 (1437926481972953088)]} 0 1
[junit4:junit4] 2> 232419 T658 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10041 (1437926481977147392)]} 0 1
[junit4:junit4] 2> 232423 T696 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[41 (1437926481977147392)]} 0 0
[junit4:junit4] 2> 232424 T677 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[41 (1437926481977147392)]} 0 5
[junit4:junit4] 2> 232427 T690 C499 P63412 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={distrib.from=http://127.0.0.1:63403/we_j/g/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10041 (1437926481981341696)]} 0 1
[junit4:junit4] 2> 232428 T679 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10041 (1437926481981341696)]} 0 5
[junit4:junit4] 2> 232498 T665 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 232500 T665 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:63412_we_j%2Fg",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63412/we_j/g"}
[junit4:junit4] 2> 232513 T671 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> 232515 T664 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> 232515 T684 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> 232516 T700 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> 232520 T657 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[42 (1437926482082004992)]} 0 1
[junit4:junit4] 2> 232524 T680 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[42 (1437926482087247872)]} 0 0
[junit4:junit4] 2> 232524 T659 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10042 (1437926482087247872)]} 0 0
[junit4:junit4] 2> 232530 T673 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10042 (1437926482092490752)]} 0 1
[junit4:junit4] 2> 232563 T656 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[40 (-1437926482128142336)]} 0 1
[junit4:junit4] 2> 232565 T676 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[40 (-1437926482130239488)]} 0 0
[junit4:junit4] 2> 232567 T655 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10040 (-1437926482132336640)]} 0 0
[junit4:junit4] 2> 232570 T678 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10040 (-1437926482135482368)]} 0 0
[junit4:junit4] 2> 232571 T660 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[43 (1437926482134433792)]} 0 2
[junit4:junit4] 2> 232575 T658 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10043 (1437926482138628096)]} 0 2
[junit4:junit4] 2> 232576 T677 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[43 (1437926482141773824)]} 0 1
[junit4:junit4] 2> 232579 T679 C500 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10043 (1437926482143870976)]} 0 1
[junit4:junit4] 2> 232669 T657 C501 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[44 (1437926482238242816)]} 0 1
[junit4:junit4] 2> ASYNC NEW_CORE C502 name=collection1 org.apache.solr.core.SolrCore@4fa1cd url=http://127.0.0.1:63391/we_j/g/collection1 node=127.0.0.1:63391_we_j%2Fg C502_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:63391_we_j%2Fg, base_url=http://127.0.0.1:63391/we_j/g, leader=true}
[junit4:junit4] 2> 232681 T656 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10044 (1437926482250825728)]} 0 1
[junit4:junit4] 2> ASYNC NEW_CORE C503 name=collection1 org.apache.solr.core.SolrCore@826a5f url=http://127.0.0.1:63403/we_j/g/collection1 node=127.0.0.1:63403_we_j%2Fg C503_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:63403_we_j%2Fg, base_url=http://127.0.0.1:63403/we_j/g, leader=true}
[junit4:junit4] 2> 232683 T680 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[44 (1437926482253971456)]} 0 0
[junit4:junit4] 2> 232687 T673 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10044 (1437926482256068608)]} 0 2
[junit4:junit4] 2> 232774 T655 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[45 (1437926482348343296)]} 0 1
[junit4:junit4] 2> 232776 T660 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10045 (1437926482350440448)]} 0 1
[junit4:junit4] 2> 232778 T676 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[45 (1437926482352537600)]} 0 1
[junit4:junit4] 2> 232780 T677 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10045 (1437926482354634752)]} 0 1
[junit4:junit4] 2> 232835 T658 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10046 (1437926482412306432)]} 0 1
[junit4:junit4] 2> 232835 T659 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[46 (1437926482413355008)]} 0 0
[junit4:junit4] 2> 232839 T680 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10046 (1437926482417549312)]} 0 0
[junit4:junit4] 2> 232841 T679 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[46 (1437926482418597888)]} 0 2
[junit4:junit4] 2> 232882 T656 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10046 (-1437926482462638080)]} 0 0
[junit4:junit4] 2> 232885 T657 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[46 (-1437926482465783808)]} 0 0
[junit4:junit4] 2> 232886 T673 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10046 (-1437926482466832384)]} 0 0
[junit4:junit4] 2> 232888 T678 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[46 (-1437926482468929536)]} 0 0
[junit4:junit4] 2> 232890 T655 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10047 (1437926482469978112)]} 0 1
[junit4:junit4] 2> 232891 T660 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[47 (1437926482472075264)]} 0 0
[junit4:junit4] 2> 232893 T677 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10047 (1437926482473123840)]} 0 1
[junit4:junit4] 2> 232895 T676 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[47 (1437926482475220992)]} 0 1
[junit4:junit4] 2> 232928 T658 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10048 (1437926482510872576)]} 0 1
[junit4:junit4] 2> 232929 T659 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[48 (1437926482511921152)]} 0 0
[junit4:junit4] 2> 232931 T680 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10048 (1437926482514018304)]} 0 0
[junit4:junit4] 2> 232932 T679 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[48 (1437926482515066880)]} 0 0
[junit4:junit4] 2> 233025 T656 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10049 (1437926482611535872)]} 0 1
[junit4:junit4] 2> 233029 T673 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10049 (1437926482615730176)]} 0 1
[junit4:junit4] 2> 233047 T657 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[49 (1437926482634604544)]} 0 1
[junit4:junit4] 2> 233051 T678 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[49 (1437926482638798848)]} 0 1
[junit4:junit4] 2> 233079 T655 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10050 (1437926482669207552)]} 0 0
[junit4:junit4] 2> 233083 T677 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10050 (1437926482673401856)]} 0 0
[junit4:junit4] 2> 233088 T658 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[50 (1437926482677596160)]} 0 1
[junit4:junit4] 2> 233091 T676 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[50 (1437926482680741888)]} 0 1
[junit4:junit4] 2> 233116 T659 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10051 (1437926482708004864)]} 0 0
[junit4:junit4] 2> 233119 T680 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10051 (1437926482711150592)]} 0 0
[junit4:junit4] 2> 233123 T656 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[51 (1437926482714296320)]} 0 1
[junit4:junit4] 2> 233126 T679 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[51 (1437926482717442048)]} 0 1
[junit4:junit4] 2> 233140 T657 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10052 (1437926482732122112)]} 0 1
[junit4:junit4] 2> 233143 T673 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10052 (1437926482736316416)]} 0 0
[junit4:junit4] 2> 233148 T660 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[52 (1437926482740510720)]} 0 1
[junit4:junit4] 2> 233151 T678 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[52 (1437926482743656448)]} 0 1
[junit4:junit4] 2> 233246 T655 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10053 (1437926482843271168)]} 0 1
[junit4:junit4] 2> 233249 T677 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10053 (1437926482847465472)]} 0 0
[junit4:junit4] 2> 233254 T658 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[53 (1437926482851659776)]} 0 1
[junit4:junit4] 2> 233257 T680 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[53 (1437926482854805504)]} 0 0
[junit4:junit4] 2> 233313 T659 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10054 (1437926482913525760)]} 0 1
[junit4:junit4] 2> 233316 T679 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10054 (1437926482917720064)]} 0 0
[junit4:junit4] 2> 233320 T656 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[54 (1437926482920865792)]} 0 1
[junit4:junit4] 2> 233323 T673 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[54 (1437926482924011520)]} 0 1
[junit4:junit4] 2> 233373 T657 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10051 (-1437926482977488896)]} 0 0
[junit4:junit4] 2> 233377 T678 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10051 (-1437926482981683200)]} 0 0
[junit4:junit4] 2> 233379 T660 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[51 (-1437926482983780352)]} 0 0
[junit4:junit4] 2> 233381 T655 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10055 (1437926482984828928)]} 0 1
[junit4:junit4] 2> 233382 T676 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[51 (-1437926482986926080)]} 0 0
[junit4:junit4] 2> 233385 T677 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10055 (1437926482989023232)]} 0 1
[junit4:junit4] 2> 233386 T658 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[55 (1437926482990071808)]} 0 1
[junit4:junit4] 2> 233390 T680 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[55 (1437926482994266112)]} 0 1
[junit4:junit4] 2> 233404 T659 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10056 (1437926483009994752)]} 0 0
[junit4:junit4] 2> 233407 T679 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10056 (1437926483013140480)]} 0 0
[junit4:junit4] 2> 233408 T656 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[56 (1437926483014189056)]} 0 0
[junit4:junit4] 2> 233413 T673 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[56 (1437926483018383360)]} 0 1
[junit4:junit4] 2> 233468 T657 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10053 (-1437926483077103616)]} 0 0
[junit4:junit4] 2> 233472 T678 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10053 (-1437926483081297920)]} 0 0
[junit4:junit4] 2> 233472 T660 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[53 (-1437926483081297920)]} 0 0
[junit4:junit4] 2> 233475 T676 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[53 (-1437926483084443648)]} 0 0
[junit4:junit4] 2> 233476 T655 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10057 (1437926483084443648)]} 0 1
[junit4:junit4] 2> 233479 T658 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[57 (1437926483087589376)]} 0 1
[junit4:junit4] 2> 233480 T677 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10057 (1437926483088637952)]} 0 1
[junit4:junit4] 2> 233482 T680 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[57 (1437926483091783680)]} 0 0
[junit4:junit4] 2> 233517 T656 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10054 (-1437926483128483840)]} 0 0
[junit4:junit4] 2> 233518 T657 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[54 (-1437926483129532416)]} 0 0
[junit4:junit4] 2> 233520 T679 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[54 (-1437926483131629568)]} 0 0
[junit4:junit4] 2> 233520 T673 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10054 (-1437926483131629569)]} 0 0
[junit4:junit4] 2> 233527 T660 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10058 (1437926483137921025)]} 0 1
[junit4:junit4] 2> 233527 T655 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[58 (1437926483137921024)]} 0 1
[junit4:junit4] 2> 233532 T678 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[58 (1437926483144212481)]} 0 0
[junit4:junit4] 2> 233533 T676 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10058 (1437926483144212480)]} 0 1
[junit4:junit4] 2> 233537 T659 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10057 (-1437926483149455361)]} 0 0
[junit4:junit4] 2> 233537 T658 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[57 (-1437926483149455360)]} 0 0
[junit4:junit4] 2> 233540 T677 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[57 (-1437926483152601088)]} 0 0
[junit4:junit4] 2> 233540 T680 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10057 (-1437926483152601089)]} 0 0
[junit4:junit4] 2> 233546 T656 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10059 (1437926483155746816)]} 0 3
[junit4:junit4] 2> 233546 T657 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[59 (1437926483155746817)]} 0 3
[junit4:junit4] 2> 233549 T679 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10059 (1437926483162038273)]} 0 0
[junit4:junit4] 2> 233549 T673 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[59 (1437926483162038272)]} 0 0
[junit4:junit4] 2> 233607 T655 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[60 (1437926483221807105)]} 0 1
[junit4:junit4] 2> 233608 T660 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10060 (1437926483221807104)]} 0 2
[junit4:junit4] 2> 233612 T678 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[60 (1437926483227049984)]} 0 1
[junit4:junit4] 2> 233613 T676 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10060 (1437926483228098560)]} 0 1
[junit4:junit4] 2> 233696 T659 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[58 (-1437926483316178944)]} 0 0
[junit4:junit4] 2> 233700 T658 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10058 (-1437926483320373248)]} 0 0
[junit4:junit4] 2> 233700 T677 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[58 (-1437926483320373248)]} 0 0
[junit4:junit4] 2> 233703 T679 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10058 (-1437926483323518976)]} 0 0
[junit4:junit4] 2> 233703 T656 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[61 (1437926483323518976)]} 0 0
[junit4:junit4] 2> 233706 T657 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10061 (1437926483326664704)]} 0 0
[junit4:junit4] 2> 233709 T673 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[61 (1437926483328761856)]} 0 1
[junit4:junit4] 2> 233710 T678 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10061 (1437926483330859008)]} 0 0
[junit4:junit4] 2> 233752 T655 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[62 (1437926483373850624)]} 0 1
[junit4:junit4] 2> 233755 T660 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10062 (1437926483375947776)]} 0 2
[junit4:junit4] 2> 233756 T676 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[62 (1437926483378044928)]} 0 1
[junit4:junit4] 2> 233757 T680 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10062 (1437926483380142080)]} 0 0
[junit4:junit4] 2> 233841 T659 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[63 (1437926483467173888)]} 0 1
[junit4:junit4] 2> 233842 T658 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10063 (1437926483468222464)]} 0 1
[junit4:junit4] 2> 233844 T677 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[63 (1437926483471368192)]} 0 0
[junit4:junit4] 2> 233846 T679 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10063 (1437926483472416768)]} 0 1
[junit4:junit4] 2> 233865 T656 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[60 (-1437926483493388288)]} 0 0
[junit4:junit4] 2> 233867 T657 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10060 (-1437926483495485440)]} 0 0
[junit4:junit4] 2> 233868 T673 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[60 (-1437926483496534016)]} 0 0
[junit4:junit4] 2> 233870 T678 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10060 (-1437926483498631168)]} 0 0
[junit4:junit4] 2> 233873 T655 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[64 (1437926483500728320)]} 0 1
[junit4:junit4] 2> 233874 T660 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10064 (1437926483501776896)]} 0 1
[junit4:junit4] 2> 233875 T676 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[64 (1437926483503874048)]} 0 0
[junit4:junit4] 2> 233877 T680 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10064 (1437926483505971200)]} 0 0
[junit4:junit4] 2> ASYNC NEW_CORE C504 name=collection1 org.apache.solr.core.SolrCore@a920ad url=http://127.0.0.1:63412/we_j/g/collection1 node=127.0.0.1:63412_we_j%2Fg C504_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=down, core=collection1, collection=collection1, node_name=127.0.0.1:63412_we_j%2Fg, base_url=http://127.0.0.1:63412/we_j/g}
[junit4:junit4] 2> 233900 T703 C504 P63412 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:63403/we_j/g/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 233900 T703 C504 P63412 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:63412/we_j/g START replicas=[http://127.0.0.1:63403/we_j/g/collection1/] nUpdates=100
[junit4:junit4] 2> 233908 T703 C504 P63412 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 233908 T677 C503 P63403 oasc.SolrCore.execute [collection1] webapp=/we_j/g path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=3
[junit4:junit4] 2> 233908 T703 C504 P63412 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 233908 T703 C504 P63412 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 233909 T642 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 233909 T642 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 233909 T703 C504 P63412 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 233911 T703 C504 P63412 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=tlog{file=.\org.apache.solr.cloud.RecoveryZkTest-1371313535638\jetty2\tlog\tlog.0000000000000000000 refcount=1}}
[junit4:junit4] 2> 233911 T703 C504 P63412 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:63403/we_j/g/collection1/. core=collection1
[junit4:junit4] 2> 233911 T703 C504 P63412 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 233916 T642 oasc.RecoveryStrategy.close WARN Stopping recovery for zkNodeName=3core=collection1
[junit4:junit4] 2> 233920 T679 C503 P63403 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 233931 T679 C503 P63403 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@f37bb8 lockFactory=org.apache.lucene.store.NativeFSLockFactory@ada913),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@f37bb8 lockFactory=org.apache.lucene.store.NativeFSLockFactory@ada913),segFN=segments_2,generation=2}
[junit4:junit4] 2> 233933 T679 C503 P63403 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 233935 T679 C503 P63403 oass.SolrIndexSearcher.<init> Opening Searcher@1257498 realtime
[junit4:junit4] 2> 233935 T679 C503 P63403 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 233936 T679 C503 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 17
[junit4:junit4] 2> 233937 T703 C504 P63412 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 233937 T703 C504 P63412 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 233940 T673 C503 P63403 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 233940 T673 C503 P63403 oasc.SolrCore.execute [collection1] webapp=/we_j/g path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=0
[junit4:junit4] 2> 233941 T703 C504 P63412 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 233941 T703 C504 P63412 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 233941 T703 C504 P63412 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 233943 T678 C503 P63403 oasc.SolrCore.execute [collection1] webapp=/we_j/g path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=0
[junit4:junit4] 2> 233944 T703 C504 P63412 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 5
[junit4:junit4] 2> 233944 T703 C504 P63412 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.RecoveryZkTest-1371313535638/jetty2\index.20130615222556267
[junit4:junit4] 2> 233944 T703 C504 P63412 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@1b8935b lockFactory=org.apache.lucene.store.NativeFSLockFactory@652f4d) fullCopy=false
[junit4:junit4] 2> 233947 T676 C503 P63403 oasc.SolrCore.execute [collection1] webapp=/we_j/g path=/replication params={file=_0.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 233951 T680 C503 P63403 oasc.SolrCore.execute [collection1] webapp=/we_j/g path=/replication params={file=_0.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 233955 T677 C503 P63403 oasc.SolrCore.execute [collection1] webapp=/we_j/g path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 233959 T659 C502 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[65 (1437926483590905856)]} 0 1
[junit4:junit4] 2> 233959 T679 C503 P63403 oasc.SolrCore.execute [collection1] webapp=/we_j/g path=/replication params={file=_0_1.del&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> ASYNC NEW_CORE C505 name=collection1 org.apache.solr.core.SolrCore@4fa1cd url=http://127.0.0.1:63391/we_j/g/collection1 node=127.0.0.1:63391_we_j%2Fg C505_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:63391_we_j%2Fg, base_url=http://127.0.0.1:63391/we_j/g, leader=true}
[junit4:junit4] 2> 233966 T659 C505 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10065 (1437926483598245888)]} 0 1
[junit4:junit4] 2> ASYNC NEW_CORE C506 name=collection1 org.apache.solr.core.SolrCore@826a5f url=http://127.0.0.1:63403/we_j/g/collection1 node=127.0.0.1:63403_we_j%2Fg C506_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:63403_we_j%2Fg, base_url=http://127.0.0.1:63403/we_j/g, leader=true}
[junit4:junit4] 2> 233970 T678 C506 P63403 oasc.SolrCore.execute [collection1] webapp=/we_j/g path=/replication params={file=_0.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 233970 T673 C506 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[65 (1437926483598245888)]} 0 5
[junit4:junit4] 2> ASYNC NEW_CORE C507 name=collection1 org.apache.solr.core.SolrCore@a920ad url=http://127.0.0.1:63412/we_j/g/collection1 node=127.0.0.1:63412_we_j%2Fg C507_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=down, core=collection1, collection=collection1, node_name=127.0.0.1:63412_we_j%2Fg, base_url=http://127.0.0.1:63412/we_j/g}
[junit4:junit4] 2> 233971 T703 C507 P63412 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 233973 T703 C507 P63412 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 233973 T703 C507 P63412 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 233975 T703 C507 P63412 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4:junit4] 2> 233975 T676 C506 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10065 (1437926483603488768)]} 0 5
[junit4:junit4] 2> 233982 T703 C507 P63412 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1694399 lockFactory=org.apache.lucene.store.NativeFSLockFactory@a490d4),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1694399 lockFactory=org.apache.lucene.store.NativeFSLockFactory@a490d4),segFN=segments_2,generation=2}
[junit4:junit4] 2> 233983 T703 C507 P63412 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 233988 T703 C507 P63412 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1694399 lockFactory=org.apache.lucene.store.NativeFSLockFactory@a490d4),segFN=segments_2,generation=2}
[junit4:junit4] 2> 233988 T703 C507 P63412 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 233988 T703 C507 P63412 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 233990 T703 C507 P63412 oass.SolrIndexSearcher.<init> Opening Searcher@12250ef main
[junit4:junit4] 2> 233991 T702 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@12250ef main{StandardDirectoryReader(segments_2:5:nrt _0(4.4):c33/20 _1(4.4):c7/2)}
[junit4:junit4] 2> 233992 T703 C507 P63412 oasc.CachingDirectoryFactory.closeCacheValue looking to close .\org.apache.solr.cloud.RecoveryZkTest-1371313535638/jetty2\index.20130615222556267 [CachedDir<<refCount=0;path=.\org.apache.solr.cloud.RecoveryZkTest-1371313535638/jetty2\index.20130615222556267;done=true>>]
[junit4:junit4] 2> 233992 T703 C507 P63412 oasc.CachingDirectoryFactory.close Closing directory: .\org.apache.solr.cloud.RecoveryZkTest-1371313535638/jetty2\index.20130615222556267
[junit4:junit4] 2> 233993 T703 C507 P63412 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: .\org.apache.solr.cloud.RecoveryZkTest-1371313535638/jetty2\index.20130615222556267
[junit4:junit4] 2> 233993 T703 C507 P63412 oasc.RecoveryStrategy.replay Replaying buffered documents. core=collection1
[junit4:junit4] 2> 233993 T711 C507 P63412 oasu.UpdateLog$LogReplayer.doReplay WARN Starting log replay tlog{file=.\org.apache.solr.cloud.RecoveryZkTest-1371313535638\jetty2\tlog\tlog.0000000000000000000 refcount=2} active=true starting pos=4677
[junit4:junit4] 2> 233993 T711 C507 P63412 oasu.DirectUpdateHandler2.commit start commit{flags=2,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 233996 T711 C507 P63412 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1694399 lockFactory=org.apache.lucene.store.NativeFSLockFactory@a490d4),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1694399 lockFactory=org.apache.lucene.store.NativeFSLockFactory@a490d4),segFN=segments_3,generation=3}
[junit4:junit4] 2> 233996 T711 C507 P63412 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 233997 T711 C507 P63412 oass.SolrIndexSearcher.<init> Opening Searcher@7b4d34 main
[junit4:junit4] 2> 233997 T711 C507 P63412 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 233999 T702 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7b4d34 main{StandardDirectoryReader(segments_2:5:nrt _0(4.4):c33/20 _1(4.4):c7/2)}
[junit4:junit4] 2> 233999 T711 C507 P63412 oasup.LogUpdateProcessor.finish [collection1] {} 0 6
[junit4:junit4] 2> 233999 T711 C507 P63412 oasu.UpdateLog$LogReplayer.run WARN Log replay finished. recoveryInfo=RecoveryInfo{adds=0 deletes=0 deleteByQuery=0 errors=0 positionOfStart=4677}
[junit4:junit4] 2> 234000 T703 C507 P63412 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 234000 T703 C507 P63412 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 234000 T703 C507 P63412 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 234004 T703 C507 P63412 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 234004 T642 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@a920ad
[junit4:junit4] 2> 234006 T657 C505 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[66 (1437926483640188928)]} 0 1
[junit4:junit4] 2> 234009 T680 C506 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[66 (1437926483643334656)]} 0 1
[junit4:junit4] 2> 234012 T655 C505 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10066 (1437926483647528960)]} 0 0
[junit4:junit4] 2> 234015 T642 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=1,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=40,cumulative_deletesById=24,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 234017 T642 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 234018 T642 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 234018 T642 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 234018 T677 C506 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10066 (1437926483653820416)]} 0 0
[junit4:junit4] 2> 234022 T642 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 234022 T642 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 234022 T642 oasc.CachingDirectoryFactory.closeCacheValue looking to close .\org.apache.solr.cloud.RecoveryZkTest-1371313535638/jetty2\ [CachedDir<<refCount=0;path=.\org.apache.solr.cloud.RecoveryZkTest-1371313535638/jetty2\;done=false>>]
[junit4:junit4] 2> 234022 T642 oasc.CachingDirectoryFactory.close Closing directory: .\org.apache.solr.cloud.RecoveryZkTest-1371313535638/jetty2\
[junit4:junit4] 2> 234023 T642 oasc.CachingDirectoryFactory.closeCacheValue looking to close .\org.apache.solr.cloud.RecoveryZkTest-1371313535638/jetty2\index [CachedDir<<refCount=0;path=.\org.apache.solr.cloud.RecoveryZkTest-1371313535638/jetty2\index;done=false>>]
[junit4:junit4] 2> 234023 T642 oasc.CachingDirectoryFactory.close Closing directory: .\org.apache.solr.cloud.RecoveryZkTest-1371313535638/jetty2\index
[junit4:junit4] 2> 234027 T671 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> 234030 T684 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 234030 T664 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 234030 T664 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> 234030 T684 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> 234032 T671 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 234035 T665 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 234036 T665 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[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:63412_we_j%2Fg",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63412/we_j/g"}
[junit4:junit4] 2> 234042 T642 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/we_j/g,null}
[junit4:junit4] 2> 234046 T665 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:63412_we_j%2Fg",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:63412/we_j/g"}
[junit4:junit4] 2> 234055 T664 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> 234055 T684 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> 234055 T671 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> 234088 T660 C505 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[67 (1437926483726172160)]} 0 1
[junit4:junit4] 2> 234092 T679 C506 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[67 (1437926483730366464)]} 0 1
[junit4:junit4] 2> 234100 T658 C505 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10067 (1437926483737706496)]} 0 2
[junit4:junit4] 2> 234105 T673 C506 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10067 (1437926483745046528)]} 0 0
[junit4:junit4] 2> 234113 T656 C505 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[68 (1437926483753435136)]} 0 0
[junit4:junit4] 2> 234118 T676 C506 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[68 (1437926483758678016)]} 0 0
[junit4:junit4] 2> 234125 T659 C505 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10068 (1437926483766018048)]} 0 0
[junit4:junit4] 2> 234128 T680 C506 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10068 (1437926483769163776)]} 0 0
[junit4:junit4] 2> 234191 T657 C505 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[61 (-1437926483835224064)]} 0 0
[junit4:junit4] 2> 234194 T677 C506 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[61 (-1437926483838369792)]} 0 0
[junit4:junit4] 2> 234199 T655 C505 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[69 (1437926483843612672)]} 0 1
[junit4:junit4] 2> 234202 T660 C505 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10061 (-1437926483846758400)]} 0 0
[junit4:junit4] 2> 234202 T679 C506 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[69 (1437926483846758400)]} 0 0
[junit4:junit4] 2> 234205 T678 C506 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10061 (-1437926483849904128)]} 0 0
[junit4:junit4] 2> 234209 T658 C505 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10069 (1437926483853049856)]} 0 1
[junit4:junit4] 2> 234217 T673 C506 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10069 (1437926483862487040)]} 0 0
[junit4:junit4] 2> 234240 T656 C505 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[70 (1437926483885555712)]} 0 1
[junit4:junit4] 2> 234244 T676 C506 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[70 (1437926483889750016)]} 0 1
[junit4:junit4] 2> 234255 T659 C505 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10070 (1437926483902332928)]} 0 0
[junit4:junit4] 2> 234258 T680 C506 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[10070 (1437926483905478656)]} 0 0
[junit4:junit4] 2> 234278 T657 C505 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[62 (-1437926483926450176)]} 0 0
[junit4:junit4] 2> 234281 T677 C506 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[62 (-1437926483929595904)]} 0 0
[junit4:junit4] 2> 234285 T655 C505 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[71 (1437926483932741632)]} 0 1
[junit4:junit4] 2> 234288 T679 C506 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[71 (1437926483935887360)]} 0 1
[junit4:junit4] 2> 234293 T660 C505 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10062 (-1437926483942178816)]} 0 0
[junit4:junit4] 2> 234295 T642 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 234297 T678 C506 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {delete=[10062 (-1437926483946373120)]} 0 0
[junit4:junit4] 2> 234299 T642 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:63412
[junit4:junit4] 2> 234300 T658 C505 P63391 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[72 (1437926483948470272)]} 0 1
[junit4:junit4] 2> 234300 T642 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 234300 T642 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 234301 T642 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1371313547261
[junit4:junit4] 2> 234301 T642 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1371313547261\solr.xml
[junit4:junit4] 2> 234301 T642 oasc.CoreContainer.<init> New CoreContainer 17134098
[junit4:junit4] 2> 234302 T673 C506 P63403 oasup.LogUpdateProcessor.finish [collection1] webapp=/we_j/g path=/update params={wt=javabin&version=2} {add=[72 (1437926483951616000)]} 0 0
[junit4:junit4] 2> 234303 T642 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1371313547261\'
[junit4:junit4] 2> 234303 T642 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSl
[...truncated too long message...]
dn't connect to http://127.0.0.1:63403/we_j/g/collection1/, counting as success
[junit4:junit4] 2> 333524 T724 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:63412/we_j/g DONE. sync succeeded
[junit4:junit4] 2> 333524 T724 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 333524 T724 oasc.SyncStrategy.syncToMe http://127.0.0.1:63412/we_j/g/collection1/ has no replicas
[junit4:junit4] 2> 333525 T724 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:63412/we_j/g/collection1/
[junit4:junit4] 2> 333525 T724 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 333536 T724 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4:junit4] 2> 333536 T724 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> 333537 T724 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> 333555 T642 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 333555 T642 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 333557 T642 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@beb8f0
[junit4:junit4] 2> 333567 T642 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=43,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=38,cumulative_deletesById=26,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 333567 T642 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 333567 T642 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 333567 T642 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 333571 T642 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 333572 T642 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 333572 T642 oasc.CachingDirectoryFactory.closeCacheValue looking to close .\org.apache.solr.cloud.RecoveryZkTest-1371313535638/jetty2\ [CachedDir<<refCount=0;path=.\org.apache.solr.cloud.RecoveryZkTest-1371313535638/jetty2\;done=false>>]
[junit4:junit4] 2> 333572 T642 oasc.CachingDirectoryFactory.close Closing directory: .\org.apache.solr.cloud.RecoveryZkTest-1371313535638/jetty2\
[junit4:junit4] 2> 333572 T642 oasc.CachingDirectoryFactory.closeCacheValue looking to close .\org.apache.solr.cloud.RecoveryZkTest-1371313535638/jetty2\index [CachedDir<<refCount=0;path=.\org.apache.solr.cloud.RecoveryZkTest-1371313535638/jetty2\index;done=false>>]
[junit4:junit4] 2> 333572 T642 oasc.CachingDirectoryFactory.close Closing directory: .\org.apache.solr.cloud.RecoveryZkTest-1371313535638/jetty2\index
[junit4:junit4] 2> 333578 T735 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89870403872227338-127.0.0.1:63412_we_j%2Fg-n_0000000003) am no longer a leader.
[junit4:junit4] 2> 333580 T724 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 333581 T724 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> 333581 T724 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 333592 T642 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/we_j/g,null}
[junit4:junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1371313535638\zookeeper\server1\data\version-2\log.1 FAILED !!!!!
[junit4:junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1371313535638\zookeeper\server1\data\version-2 FAILED !!!!!
[junit4:junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1371313535638\zookeeper\server1\data FAILED !!!!!
[junit4:junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1371313535638\zookeeper\server1 FAILED !!!!!
[junit4:junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1371313535638\zookeeper FAILED !!!!!
[junit4:junit4] 2> !!!! WARNING: best effort to remove C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-1371313535638 FAILED !!!!!
[junit4:junit4] 2> 333671 T642 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 333672 T642 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:63384 63384
[junit4:junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4:junit4] 1> safe stop:
[junit4:junit4] 1> safe stop:
[junit4:junit4] 1> safe stop:
[junit4:junit4] 1> safe stop:
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=RecoveryZkTest -Dtests.method=testDistribSearch -Dtests.seed=7E4C8BD163DD3574 -Dtests.slow=true -Dtests.locale=es_PY -Dtests.timezone=Asia/Yekaterinburg -Dtests.file.encoding=US-ASCII
[junit4:junit4] FAILURE 122s | RecoveryZkTest.testDistribSearch <<<
[junit4:junit4] > Throwable #1: java.lang.AssertionError: expected:<186> but was:<38>
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([7E4C8BD163DD3574:FFAA05C914825548]:0)
[junit4:junit4] > at org.apache.solr.cloud.RecoveryZkTest.doTest(RecoveryZkTest.java:108)
[junit4:junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:662)
[junit4:junit4] 2> 335640 T642 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {range_facet_l=MockVariableIntBlock(baseBlockSize=40), text=PostingsFormat(name=Memory doPackFST= true), _version_=PostingsFormat(name=MockRandom), rnd_b=PostingsFormat(name=Asserting), intDefault=PostingsFormat(name=MockRandom), id=PostingsFormat(name=Asserting), timestamp=MockVariableIntBlock(baseBlockSize=40), a_t=MockVariableIntBlock(baseBlockSize=40), range_facet_sl=PostingsFormat(name=Asserting), range_facet_si=MockVariableIntBlock(baseBlockSize=40), other_tl1=PostingsFormat(name=MockRandom), multiDefault=MockVariableIntBlock(baseBlockSize=40), a_si=PostingsFormat(name=MockRandom)}, docValues:{}, sim=DefaultSimilarity, locale=es_PY, timezone=Asia/Yekaterinburg
[junit4:junit4] 2> NOTE: Windows 7 6.1 x86/Sun Microsystems Inc. 1.6.0_45 (32-bit)/cpus=2,threads=2,free=42125112,total=85143552
[junit4:junit4] 2> NOTE: All tests run in this JVM: [ChaosMonkeyShardSplitTest, TestReversedWildcardFilterFactory, TestCollationField, TermVectorComponentTest, TestPartialUpdateDeduplication, SolrCoreTest, SchemaVersionSpecificBehaviorTest, BadComponentTest, SoftAutoCommitTest, CurrencyFieldXmlFileTest, SolrRequestParserTest, LeaderElectionTest, TestXIncludeConfig, TestSuggestSpellingConverter, TestLMDirichletSimilarityFactory, TestSweetSpotSimilarityFactory, NumericFieldsTest, TestManagedSchema, ReturnFieldsTest, TestSolrXMLSerializer, DocumentAnalysisRequestHandlerTest, TestSolrJ, TestSolrIndexConfig, RequestHandlersTest, DistributedQueryElevationComponentTest, PreAnalyzedUpdateProcessorTest, TestDefaultSimilarityFactory, TestManagedSchemaFieldResource, TestUtils, TestCopyFieldCollectionResource, TestDocSet, TestExtendedDismaxParser, MoreLikeThisHandlerTest, TestSolrQueryParserDefaultOperatorResource, TestIndexSearcher, TestBadConfig, SuggesterTSTTest, TestUpdate, TestDefaultSearchFieldResource, BinaryUpdateRequestHandlerTest, RecoveryZkTest]
[junit4:junit4] Completed in 122.37s, 1 test, 1 failure <<< FAILURES!
[...truncated 799 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:392: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:372: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\build.xml:181: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\solr\common-build.xml:437: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:1246: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-4.x-Windows\lucene\common-build.xml:890: There were test failures: 297 suites, 1246 tests, 1 failure, 20 ignored (14 assumptions)
Total time: 69 minutes 54 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 32bit/jdk1.6.0_45 -client -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure