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/26 02:16:19 UTC
[JENKINS] Lucene-Solr-trunk-MacOSX (64bit/jdk1.7.0) - Build # 596 -
Still Failing!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-MacOSX/596/
Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseSerialGC
1 tests failed.
REGRESSION: org.apache.solr.cloud.RecoveryZkTest.testDistribSearch
Error Message:
expected:<130> but was:<26>
Stack Trace:
java.lang.AssertionError: expected:<130> but was:<26>
at __randomizedtesting.SeedInfo.seed([10E034D761A8A91B:9106BACF16F7C927]: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:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Build Log:
[...truncated 9372 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.RecoveryZkTest
[junit4:junit4] 2> 712125 T1769 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /e_ro/m
[junit4:junit4] 2> 712131 T1769 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./solrtest-RecoveryZkTest-1372203311977
[junit4:junit4] 2> 712134 T1769 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 712139 T1770 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 712240 T1769 oasc.ZkTestServer.run start zk server on port:49642
[junit4:junit4] 2> 712242 T1769 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 712253 T1776 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1afdbb08 name:ZooKeeperConnection Watcher:127.0.0.1:49642 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 712253 T1769 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 712253 T1769 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 712263 T1769 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 712268 T1778 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6b41ad23 name:ZooKeeperConnection Watcher:127.0.0.1:49642/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 712268 T1769 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 712268 T1769 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 712277 T1769 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 712290 T1769 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 712297 T1769 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 712304 T1769 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 712304 T1769 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 712315 T1769 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 712315 T1769 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 712323 T1769 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 712324 T1769 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 712331 T1769 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 712332 T1769 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 712339 T1769 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 712340 T1769 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 712347 T1769 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 712347 T1769 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 712360 T1769 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 712360 T1769 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 712368 T1769 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 712368 T1769 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 712376 T1769 oasc.AbstractZkTestCase.putConfig put /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 712376 T1769 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 712823 T1769 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 712831 T1769 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49645
[junit4:junit4] 2> 712831 T1769 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 712832 T1769 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 712832 T1769 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1372203312231
[junit4:junit4] 2> 712833 T1769 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1372203312231/solr.xml
[junit4:junit4] 2> 712833 T1769 oasc.CoreContainer.<init> New CoreContainer 382108976
[junit4:junit4] 2> 712834 T1769 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1372203312231/'
[junit4:junit4] 2> 712834 T1769 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1372203312231/'
[junit4:junit4] 2> 712985 T1769 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 712986 T1769 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 712986 T1769 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 712987 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 712987 T1769 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 712988 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 712988 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 712989 T1769 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 712989 T1769 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 712990 T1769 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 713014 T1769 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 713015 T1769 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49642/solr
[junit4:junit4] 2> 713016 T1769 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 713017 T1769 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 713021 T1789 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@756c05c name:ZooKeeperConnection Watcher:127.0.0.1:49642 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 713022 T1769 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 713027 T1769 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 713047 T1769 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 713052 T1791 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@48357908 name:ZooKeeperConnection Watcher:127.0.0.1:49642/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 713052 T1769 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 713056 T1769 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 713065 T1769 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 713073 T1769 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 713077 T1769 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49645_e_ro%2Fm
[junit4:junit4] 2> 713080 T1769 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49645_e_ro%2Fm
[junit4:junit4] 2> 713093 T1769 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 713107 T1769 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 713114 T1769 oasc.Overseer.start Overseer (id=89928716254773251-127.0.0.1:49645_e_ro%2Fm-n_0000000000) starting
[junit4:junit4] 2> 713121 T1769 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 713133 T1792 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 713137 T1793 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 713147 T1769 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 713153 T1769 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 713159 T1769 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 713171 T1794 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 713172 T1794 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 714649 T1792 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 714651 T1792 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:49645_e_ro%2Fm",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49645/e_ro/m"}
[junit4:junit4] 2> 714651 T1792 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 714652 T1792 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 714667 T1791 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> 715176 T1794 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1372203312231/collection1
[junit4:junit4] 2> 715176 T1794 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 715178 T1794 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 715179 T1794 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 715182 T1794 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1372203312231/collection1/'
[junit4:junit4] 2> 715184 T1794 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1372203312231/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 715185 T1794 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1372203312231/collection1/lib/README' to classloader
[junit4:junit4] 2> 715265 T1794 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 715363 T1794 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 715366 T1794 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 715372 T1794 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 716201 T1794 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 716212 T1794 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 716217 T1794 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 716248 T1794 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 716257 T1794 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 716269 T1794 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 716272 T1794 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 716272 T1794 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 716272 T1794 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 716275 T1794 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 716275 T1794 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 716276 T1794 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 716276 T1794 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-controljetty-1372203312231/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1372203311977/control/data/
[junit4:junit4] 2> 716276 T1794 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7ec40b92
[junit4:junit4] 2> 716277 T1794 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 716278 T1794 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1372203311977/control/data
[junit4:junit4] 2> 716278 T1794 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1372203311977/control/data/index/
[junit4:junit4] 2> 716279 T1794 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1372203311977/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 716280 T1794 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1372203311977/control/data/index
[junit4:junit4] 2> 716285 T1794 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5df92110 lockFactory=org.apache.lucene.store.NativeFSLockFactory@73d5786f),segFN=segments_1,generation=1}
[junit4:junit4] 2> 716285 T1794 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 716289 T1794 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 716289 T1794 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 716290 T1794 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 716291 T1794 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 716291 T1794 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 716292 T1794 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 716292 T1794 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 716293 T1794 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 716293 T1794 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 716307 T1794 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 716318 T1794 oass.SolrIndexSearcher.<init> Opening Searcher@3d547187 main
[junit4:junit4] 2> 716319 T1794 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.RecoveryZkTest-1372203311977/control/data/tlog
[junit4:junit4] 2> 716320 T1794 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 716320 T1794 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 716325 T1795 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3d547187 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 716326 T1794 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 716327 T1794 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49645/e_ro/m collection:control_collection shard:shard1
[junit4:junit4] 2> 716333 T1794 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 716352 T1794 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 716358 T1794 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 716359 T1794 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 716359 T1794 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49645/e_ro/m/collection1/
[junit4:junit4] 2> 716359 T1794 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 716359 T1794 oasc.SyncStrategy.syncToMe http://127.0.0.1:49645/e_ro/m/collection1/ has no replicas
[junit4:junit4] 2> 716360 T1794 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49645/e_ro/m/collection1/
[junit4:junit4] 2> 716360 T1794 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 717713 T1792 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 717732 T1791 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> 717761 T1794 oasc.ZkController.register We are http://127.0.0.1:49645/e_ro/m/collection1/ and leader is http://127.0.0.1:49645/e_ro/m/collection1/
[junit4:junit4] 2> 717762 T1794 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49645/e_ro/m
[junit4:junit4] 2> 717762 T1794 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 717762 T1794 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 717763 T1794 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 717777 T1794 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 717779 T1769 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 717780 T1769 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 717780 T1769 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 717805 T1769 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 717808 T1769 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 717812 T1798 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@64bd8254 name:ZooKeeperConnection Watcher:127.0.0.1:49642/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 717812 T1769 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 717816 T1769 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 717824 T1769 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 718239 T1769 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 718244 T1769 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49649
[junit4:junit4] 2> 718245 T1769 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 718245 T1769 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 718245 T1769 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1372203317669
[junit4:junit4] 2> 718246 T1769 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1372203317669/solr.xml
[junit4:junit4] 2> 718246 T1769 oasc.CoreContainer.<init> New CoreContainer 164202453
[junit4:junit4] 2> 718247 T1769 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1372203317669/'
[junit4:junit4] 2> 718247 T1769 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1372203317669/'
[junit4:junit4] 2> 718401 T1769 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 718402 T1769 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 718403 T1769 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 718403 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 718403 T1769 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 718404 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 718404 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 718405 T1769 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 718405 T1769 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 718406 T1769 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 718426 T1769 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 718426 T1769 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49642/solr
[junit4:junit4] 2> 718427 T1769 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 718429 T1769 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 718434 T1809 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@8d1640f name:ZooKeeperConnection Watcher:127.0.0.1:49642 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 718435 T1769 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 718441 T1769 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 718485 T1769 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 718489 T1811 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5c153530 name:ZooKeeperConnection Watcher:127.0.0.1:49642/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 718489 T1769 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 718500 T1769 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 719253 T1792 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 719255 T1792 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:49645_e_ro%2Fm",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49645/e_ro/m"}
[junit4:junit4] 2> 719269 T1791 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> 719269 T1798 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> 719269 T1811 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> 719511 T1769 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49649_e_ro%2Fm
[junit4:junit4] 2> 719514 T1769 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49649_e_ro%2Fm
[junit4:junit4] 2> 719519 T1811 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> 719521 T1798 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 719522 T1798 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> 719522 T1791 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 719523 T1791 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> 719528 T1811 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 719537 T1812 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 719537 T1812 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 720783 T1792 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 720785 T1792 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:49649_e_ro%2Fm",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49649/e_ro/m"}
[junit4:junit4] 2> 720785 T1792 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 1
[junit4:junit4] 2> 720785 T1792 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 720796 T1791 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> 720805 T1798 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> 720805 T1811 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> 721552 T1812 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1372203317669/collection1
[junit4:junit4] 2> 721552 T1812 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 721554 T1812 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 721554 T1812 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 721558 T1812 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1372203317669/collection1/'
[junit4:junit4] 2> 721559 T1812 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1372203317669/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 721560 T1812 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1372203317669/collection1/lib/README' to classloader
[junit4:junit4] 2> 721628 T1812 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 721717 T1812 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 721721 T1812 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 721728 T1812 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 722549 T1812 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 722562 T1812 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 722566 T1812 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 722638 T1812 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 722648 T1812 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 722656 T1812 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 722658 T1812 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 722659 T1812 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 722660 T1812 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 722662 T1812 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 722662 T1812 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 722663 T1812 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 722663 T1812 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty1-1372203317669/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty1/
[junit4:junit4] 2> 722663 T1812 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7ec40b92
[junit4:junit4] 2> 722664 T1812 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 722665 T1812 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty1
[junit4:junit4] 2> 722665 T1812 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty1/index/
[junit4:junit4] 2> 722665 T1812 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 722666 T1812 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty1/index
[junit4:junit4] 2> 722670 T1812 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6b948d26 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7734f6ba),segFN=segments_1,generation=1}
[junit4:junit4] 2> 722670 T1812 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 722680 T1812 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 722680 T1812 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 722681 T1812 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 722682 T1812 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 722683 T1812 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 722683 T1812 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 722683 T1812 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 722684 T1812 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 722685 T1812 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 722700 T1812 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 722706 T1812 oass.SolrIndexSearcher.<init> Opening Searcher@2b4305b8 main
[junit4:junit4] 2> 722707 T1812 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty1/tlog
[junit4:junit4] 2> 722708 T1812 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 722709 T1812 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 722715 T1813 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2b4305b8 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 722718 T1812 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 722718 T1812 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49649/e_ro/m collection:collection1 shard:shard1
[junit4:junit4] 2> 722720 T1812 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 722742 T1812 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 722748 T1812 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 722748 T1812 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 722750 T1812 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:49649/e_ro/m/collection1/
[junit4:junit4] 2> 722750 T1812 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 722751 T1812 oasc.SyncStrategy.syncToMe http://127.0.0.1:49649/e_ro/m/collection1/ has no replicas
[junit4:junit4] 2> 722751 T1812 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:49649/e_ro/m/collection1/
[junit4:junit4] 2> 722751 T1812 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 723826 T1792 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 723860 T1791 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> 723873 T1798 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> 723875 T1811 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> 723903 T1812 oasc.ZkController.register We are http://127.0.0.1:49649/e_ro/m/collection1/ and leader is http://127.0.0.1:49649/e_ro/m/collection1/
[junit4:junit4] 2> 723904 T1812 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49649/e_ro/m
[junit4:junit4] 2> 723904 T1812 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 723904 T1812 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 723904 T1812 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 723909 T1812 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 723912 T1769 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 723913 T1769 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 723913 T1769 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 724349 T1769 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 724355 T1769 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49652
[junit4:junit4] 2> 724356 T1769 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 724357 T1769 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 724357 T1769 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1372203323781
[junit4:junit4] 2> 724358 T1769 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1372203323781/solr.xml
[junit4:junit4] 2> 724358 T1769 oasc.CoreContainer.<init> New CoreContainer 2123053172
[junit4:junit4] 2> 724359 T1769 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1372203323781/'
[junit4:junit4] 2> 724359 T1769 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1372203323781/'
[junit4:junit4] 2> 724525 T1769 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 724526 T1769 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 724526 T1769 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 724527 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 724527 T1769 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 724528 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 724528 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 724529 T1769 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 724529 T1769 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 724530 T1769 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 724552 T1769 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 724553 T1769 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49642/solr
[junit4:junit4] 2> 724553 T1769 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 724555 T1769 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 724559 T1825 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@77c1d334 name:ZooKeeperConnection Watcher:127.0.0.1:49642 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 724560 T1769 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 724565 T1769 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 724582 T1769 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 724587 T1827 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@76ddd7c4 name:ZooKeeperConnection Watcher:127.0.0.1:49642/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 724587 T1769 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 724597 T1769 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 725377 T1792 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 725378 T1792 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:49649_e_ro%2Fm",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49649/e_ro/m"}
[junit4:junit4] 2> 725410 T1827 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> 725410 T1798 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> 725410 T1811 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> 725413 T1791 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> 725613 T1769 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:49652_e_ro%2Fm
[junit4:junit4] 2> 725619 T1769 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:49652_e_ro%2Fm
[junit4:junit4] 2> 725634 T1811 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> 725641 T1798 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 725643 T1798 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> 725644 T1791 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 725644 T1791 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> 725647 T1827 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 725648 T1827 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> 725654 T1811 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 725666 T1828 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 725666 T1828 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 726937 T1792 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 726938 T1792 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:49652_e_ro%2Fm",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49652/e_ro/m"}
[junit4:junit4] 2> 726939 T1792 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4] 2> 726939 T1792 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 726950 T1827 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> 726950 T1791 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> 726954 T1798 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> 726955 T1811 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> 727671 T1828 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1372203323781/collection1
[junit4:junit4] 2> 727672 T1828 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 727673 T1828 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 727674 T1828 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 727677 T1828 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1372203323781/collection1/'
[junit4:junit4] 2> 727678 T1828 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1372203323781/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 727679 T1828 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1372203323781/collection1/lib/README' to classloader
[junit4:junit4] 2> 727761 T1828 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 727849 T1828 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 727853 T1828 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 727862 T1828 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 728688 T1828 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 728699 T1828 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 728708 T1828 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 728741 T1828 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 728748 T1828 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 728756 T1828 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 728759 T1828 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 728759 T1828 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 728760 T1828 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 728762 T1828 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 728763 T1828 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 728763 T1828 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 728764 T1828 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1372203323781/collection1/, dataDir=./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty2/
[junit4:junit4] 2> 728764 T1828 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7ec40b92
[junit4:junit4] 2> 728764 T1828 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 728765 T1828 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty2
[junit4:junit4] 2> 728765 T1828 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty2/index/
[junit4:junit4] 2> 728766 T1828 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 728766 T1828 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty2/index
[junit4:junit4] 2> 728770 T1828 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1d5189b8 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2b54966c),segFN=segments_1,generation=1}
[junit4:junit4] 2> 728770 T1828 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 728774 T1828 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 728775 T1828 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 728776 T1828 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 728781 T1828 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 728783 T1828 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 728783 T1828 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 728783 T1828 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 728784 T1828 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 728785 T1828 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 728798 T1828 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 728806 T1828 oass.SolrIndexSearcher.<init> Opening Searcher@50c583c main
[junit4:junit4] 2> 728806 T1828 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty2/tlog
[junit4:junit4] 2> 728808 T1828 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 728808 T1828 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 728815 T1829 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@50c583c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 728818 T1828 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 728819 T1828 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:49652/e_ro/m collection:collection1 shard:shard1
[junit4:junit4] 2> 728826 T1828 oasc.ZkController.register We are http://127.0.0.1:49652/e_ro/m/collection1/ and leader is http://127.0.0.1:49649/e_ro/m/collection1/
[junit4:junit4] 2> 728826 T1828 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:49652/e_ro/m
[junit4:junit4] 2> 728826 T1828 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 728827 T1828 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C1581 name=collection1 org.apache.solr.core.SolrCore@53198fc9 url=http://127.0.0.1:49652/e_ro/m/collection1 node=127.0.0.1:49652_e_ro%2Fm C1581_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:49652_e_ro%2Fm, base_url=http://127.0.0.1:49652/e_ro/m}
[junit4:junit4] 2> 728828 T1830 C1581 P49652 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 728829 T1828 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 728830 T1830 C1581 P49652 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 728830 T1830 C1581 P49652 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 728831 T1830 C1581 P49652 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 728834 T1769 oass.SolrDispatchFilter.init user.dir=/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0
[junit4:junit4] 2> 728834 T1769 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 728834 T1769 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 728837 T1830 C1581 P49652 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 728859 T1769 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 728862 T1803 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 3, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> ASYNC NEW_CORE C1582 name=collection1 org.apache.solr.core.SolrCore@1a7ce791 url=http://127.0.0.1:49645/e_ro/m/collection1 node=127.0.0.1:49645_e_ro%2Fm C1582_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:49645_e_ro%2Fm, base_url=http://127.0.0.1:49645/e_ro/m, leader=true}
[junit4:junit4] 2> 728881 T1786 C1582 P49645 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5df92110 lockFactory=org.apache.lucene.store.NativeFSLockFactory@73d5786f),segFN=segments_1,generation=1}
[junit4:junit4] 2> 728882 T1786 C1582 P49645 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 728886 T1786 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10001 (1438859477619048448)]} 0 8
[junit4:junit4] 2> 728886 T1785 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[1 (1438859477620097024)]} 0 8
[junit4:junit4] 2> ASYNC NEW_CORE C1583 name=collection1 org.apache.solr.core.SolrCore@7bf91eea url=http://127.0.0.1:49649/e_ro/m/collection1 node=127.0.0.1:49649_e_ro%2Fm C1583_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:49649_e_ro%2Fm, base_url=http://127.0.0.1:49649/e_ro/m, leader=true}
[junit4:junit4] 2> 728916 T1805 C1583 P49649 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6b948d26 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7734f6ba),segFN=segments_1,generation=1}
[junit4:junit4] 2> 728918 T1805 C1583 P49649 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 728921 T1805 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10001 (1438859477655748608)]} 0 8
[junit4:junit4] 2> 728922 T1806 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[1 (1438859477655748609)]} 0 9
[junit4:junit4] 2> 728955 T1787 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10002 (1438859477697691648)]} 0 2
[junit4:junit4] 2> 728963 T1782 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[2 (1438859477701885952)]} 0 8
[junit4:junit4] 2> 728968 T1801 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10002 (1438859477711323136)]} 0 2
[junit4:junit4] 2> 728969 T1802 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[2 (1438859477713420288)]} 0 1
[junit4:junit4] 2> 729072 T1784 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10003 (1438859477820375040)]} 0 2
[junit4:junit4] 2> 729073 T1786 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[3 (1438859477821423616)]} 0 3
[junit4:junit4] 2> 729077 T1804 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10003 (1438859477825617920)]} 0 2
[junit4:junit4] 2> 729078 T1805 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[3 (1438859477826666496)]} 0 2
[junit4:junit4] 2> 729111 T1785 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10001 (-1438859477863366656)]} 0 1
[junit4:junit4] 2> 729112 T1783 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[1 (-1438859477863366657)]} 0 1
[junit4:junit4] 2> 729116 T1806 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10001 (-1438859477868609536)]} 0 1
[junit4:junit4] 2> 729118 T1801 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[1 (-1438859477869658112)]} 0 1
[junit4:junit4] 2> 729122 T1787 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10004 (1438859477872803840)]} 0 2
[junit4:junit4] 2> 729123 T1782 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[4 (1438859477874900992)]} 0 1
[junit4:junit4] 2> 729126 T1802 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10004 (1438859477878046720)]} 0 1
[junit4:junit4] 2> 729128 T1802 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[4 (1438859477880143872)]} 0 1
[junit4:junit4] 2> 729208 T1784 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[2 (-1438859477965078528)]} 0 0
[junit4:junit4] 2> 729208 T1786 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10002 (-1438859477965078529)]} 0 0
[junit4:junit4] 2> 729217 T1805 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[2 (-1438859477973467136)]} 0 1
[junit4:junit4] 2> 729218 T1806 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10002 (-1438859477974515712)]} 0 1
[junit4:junit4] 2> 729224 T1785 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10005 (1438859477980807168)]} 0 1
[junit4:junit4] 2> 729226 T1783 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[5 (1438859477980807169)]} 0 3
[junit4:junit4] 2> 729229 T1801 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10005 (1438859477986050048)]} 0 2
[junit4:junit4] 2> 729230 T1802 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[5 (1438859477987098624)]} 0 1
[junit4:junit4] 2> 729241 T1787 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10003 (-1438859477999681536)]} 0 1
[junit4:junit4] 2> 729242 T1787 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[3 (-1438859478000730112)]} 0 0
[junit4:junit4] 2> 729246 T1804 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10003 (-1438859478004924416)]} 0 1
[junit4:junit4] 2> 729248 T1806 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[3 (-1438859478007021568)]} 0 1
[junit4:junit4] 2> 729251 T1784 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10006 (1438859478009118720)]} 0 1
[junit4:junit4] 2> 729254 T1786 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[6 (1438859478012264448)]} 0 1
[junit4:junit4] 2> 729257 T1805 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10006 (1438859478015410176)]} 0 1
[junit4:junit4] 2> 729260 T1801 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[6 (1438859478018555904)]} 0 1
[junit4:junit4] 2> 729312 T1785 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10004 (-1438859478074130432)]} 0 0
[junit4:junit4] 2> 729314 T1783 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[4 (-1438859478076227584)]} 0 0
[junit4:junit4] 2> 729319 T1802 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10004 (-1438859478080421888)]} 0 1
[junit4:junit4] 2> 729320 T1802 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[4 (-1438859478082519040)]} 0 1
[junit4:junit4] 2> 729325 T1787 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10007 (1438859478086713344)]} 0 2
[junit4:junit4] 2> 729327 T1787 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[7 (1438859478088810496)]} 0 1
[junit4:junit4] 2> 729336 T1805 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10007 (1438859478095101952)]} 0 5
[junit4:junit4] 2> 729340 T1801 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[7 (1438859478101393408)]} 0 2
[junit4:junit4] 2> 729381 T1784 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10005 (-1438859478145433600)]} 0 1
[junit4:junit4] 2> 729381 T1786 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[5 (-1438859478146482176)]} 0 1
[junit4:junit4] 2> 729390 T1802 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10005 (-1438859478155919360)]} 0 0
[junit4:junit4] 2> 729393 T1804 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[5 (-1438859478159065088)]} 0 0
[junit4:junit4] 2> 729397 T1783 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10008 (1438859478161162240)]} 0 2
[junit4:junit4] 2> 729400 T1787 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[8 (1438859478165356544)]} 0 1
[junit4:junit4] 2> 729404 T1806 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10008 (1438859478168502272)]} 0 2
[junit4:junit4] 2> 729407 T1805 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[8 (1438859478171648000)]} 0 2
[junit4:junit4] 2> 729450 T1782 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10009 (1438859478214639616)]} 0 5
[junit4:junit4] 2> 729452 T1784 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[9 (1438859478218833920)]} 0 2
[junit4:junit4] 2> 729455 T1801 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10009 (1438859478223028224)]} 0 1
[junit4:junit4] 2> 729456 T1802 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[9 (1438859478224076800)]} 0 1
[junit4:junit4] 2> 729497 T1785 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10010 (1438859478264971264)]} 0 4
[junit4:junit4] 2> 729499 T1786 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10 (1438859478266019840)]} 0 5
[junit4:junit4] 2> 729509 T1804 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10010 (1438859478277554176)]} 0 3
[junit4:junit4] 2> 729512 T1806 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10 (1438859478281748480)]} 0 2
[junit4:junit4] 2> 729534 T1783 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10006 (-1438859478306914304)]} 0 0
[junit4:junit4] 2> 729535 T1787 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[6 (-1438859478307962880)]} 0 0
[junit4:junit4] 2> 729538 T1805 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10006 (-1438859478310060032)]} 0 1
[junit4:junit4] 2> 729539 T1805 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[6 (-1438859478311108608)]} 0 1
[junit4:junit4] 2> 729542 T1782 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10011 (1438859478314254336)]} 0 2
[junit4:junit4] 2> 729546 T1784 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[11 (1438859478317400064)]} 0 1
[junit4:junit4] 2> 729548 T1802 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10011 (1438859478319497216)]} 0 2
[junit4:junit4] 2> 729551 T1804 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[11 (1438859478323691520)]} 0 2
[junit4:junit4] 2> 729652 T1785 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10012 (1438859478428549120)]} 0 3
[junit4:junit4] 2> 729654 T1785 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[12 (1438859478431694848)]} 0 1
[junit4:junit4] 2> 729659 T1805 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[12 (1438859478436937728)]} 0 2
[junit4:junit4] 2> 729660 T1806 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10012 (1438859478436937729)]} 0 3
[junit4:junit4] 2> 729738 T1783 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[13 (1438859478516629504)]} 0 6
[junit4:junit4] 2> 729742 T1787 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10013 (1438859478523969536)]} 0 2
[junit4:junit4] 2> 729744 T1801 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[13 (1438859478525018112)]} 0 2
[junit4:junit4] 2> 729747 T1804 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10013 (1438859478529212416)]} 0 2
[junit4:junit4] 2> 729804 T1782 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[7 (-1438859478588981248)]} 0 1
[junit4:junit4] 2> 729809 T1785 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10007 (-1438859478594224128)]} 0 2
[junit4:junit4] 2> 729810 T1805 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[7 (-1438859478596321280)]} 0 0
[junit4:junit4] 2> 729820 T1806 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10007 (-1438859478606807040)]} 0 1
[junit4:junit4] 2> 729823 T1786 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[14 (1438859478607855616)]} 0 2
[junit4:junit4] 2> 729825 T1783 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10014 (1438859478611001344)]} 0 1
[junit4:junit4] 2> 729832 T1802 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[14 (1438859478618341376)]} 0 2
[junit4:junit4] 2> 729833 T1801 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10014 (1438859478618341377)]} 0 3
[junit4:junit4] 2> 729879 T1787 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[15 (1438859478666575872)]} 0 2
[junit4:junit4] 2> 729880 T1784 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10015 (1438859478667624448)]} 0 3
[junit4:junit4] 2> 729885 T1804 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10015 (1438859478673915904)]} 0 1
[junit4:junit4] 2> 729886 T1805 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[15 (1438859478673915905)]} 0 2
[junit4:junit4] 2> 729899 T1782 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10008 (-1438859478688595968)]} 0 1
[junit4:junit4] 2> 729900 T1785 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[8 (-1438859478689644544)]} 0 1
[junit4:junit4] 2> 729902 T1806 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10008 (-1438859478692790272)]} 0 0
[junit4:junit4] 2> 729906 T1802 C1583 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[8 (-1438859478696984576)]} 0 1
[junit4:junit4] 2> 729911 T1786 C1582 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10016 (1438859478700130304)]} 0 2
[junit4:junit4] 2> ASYNC NEW_CORE C1584 name=collection1 org.apache.solr.core.SolrCore@1a7ce791 url=http://127.0.0.1:49645/e_ro/m/collection1 node=127.0.0.1:49645_e_ro%2Fm C1584_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:49645_e_ro%2Fm, base_url=http://127.0.0.1:49645/e_ro/m, leader=true}
[junit4:junit4] 2> 729912 T1783 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[16 (1438859478702227456)]} 0 1
[junit4:junit4] 2> ASYNC NEW_CORE C1585 name=collection1 org.apache.solr.core.SolrCore@7bf91eea url=http://127.0.0.1:49649/e_ro/m/collection1 node=127.0.0.1:49649_e_ro%2Fm C1585_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:49649_e_ro%2Fm, base_url=http://127.0.0.1:49649/e_ro/m, leader=true}
[junit4:junit4] 2> 729928 T1801 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10016 (1438859478717956096)]} 0 2
[junit4:junit4] 2> 729930 T1804 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[16 (1438859478721101824)]} 0 2
[junit4:junit4] 2> 729969 T1787 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10009 (-1438859478763044864)]} 0 1
[junit4:junit4] 2> 729971 T1784 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[9 (-1438859478765142016)]} 0 1
[junit4:junit4] 2> 729973 T1805 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10009 (-1438859478767239168)]} 0 1
[junit4:junit4] 2> 729975 T1806 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[9 (-1438859478769336320)]} 0 0
[junit4:junit4] 2> 729978 T1782 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10017 (1438859478770384896)]} 0 2
[junit4:junit4] 2> 729985 T1785 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[17 (1438859478777724928)]} 0 2
[junit4:junit4] 2> 729987 T1802 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10017 (1438859478780870656)]} 0 1
[junit4:junit4] 2> 729989 T1792 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 729991 T1792 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:49652_e_ro%2Fm",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49652/e_ro/m"}
[junit4:junit4] 2> 729993 T1801 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[17 (1438859478787162112)]} 0 2
[junit4:junit4] 2> 730008 T1827 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> 730008 T1798 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> 730009 T1791 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> 730009 T1786 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10010 (-1438859478803939328)]} 0 1
[junit4:junit4] 2> 730009 T1811 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> 730019 T1783 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10 (-1438859478815473664)]} 0 0
[junit4:junit4] 2> ASYNC NEW_CORE C1586 name=collection1 org.apache.solr.core.SolrCore@53198fc9 url=http://127.0.0.1:49652/e_ro/m/collection1 node=127.0.0.1:49652_e_ro%2Fm C1586_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:49652_e_ro%2Fm, base_url=http://127.0.0.1:49652/e_ro/m}
[junit4:junit4] 2> 730038 T1820 C1586 P49652 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1d5189b8 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2b54966c),segFN=segments_1,generation=1}
[junit4:junit4] 2> 730040 T1820 C1586 P49652 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 730041 T1820 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10010 (-1438859478817570816)]} 0 7
[junit4:junit4] 2> 730043 T1804 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10010 (-1438859478817570816)]} 0 22
[junit4:junit4] 2> 730043 T1821 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10 (-1438859478822813696)]} 0 6
[junit4:junit4] 2> 730044 T1805 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10 (-1438859478822813696)]} 0 18
[junit4:junit4] 2> 730049 T1787 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[18 (1438859478844833792)]} 0 2
[junit4:junit4] 2> 730049 T1784 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10018 (1438859478844833793)]} 0 2
[junit4:junit4] 2> 730058 T1822 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[18 (1438859478850076672)]} 0 2
[junit4:junit4] 2> 730060 T1806 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[18 (1438859478850076672)]} 0 8
[junit4:junit4] 2> 730064 T1823 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10018 (1438859478852173824)]} 0 3
[junit4:junit4] 2> 730065 T1802 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10018 (1438859478852173824)]} 0 11
[junit4:junit4] 2> 730148 T1782 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[12 (-1438859478950739968)]} 0 1
[junit4:junit4] 2> 730151 T1782 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10012 (-1438859478953885696)]} 0 0
[junit4:junit4] 2> 730156 T1818 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[12 (-1438859478955982848)]} 0 0
[junit4:junit4] 2> 730158 T1818 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10012 (-1438859478957031424)]} 0 1
[junit4:junit4] 2> 730158 T1801 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[12 (-1438859478955982848)]} 0 5
[junit4:junit4] 2> 730159 T1805 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10012 (-1438859478957031424)]} 0 5
[junit4:junit4] 2> 730163 T1786 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[19 (1438859478965420032)]} 0 2
[junit4:junit4] 2> 730164 T1783 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10019 (1438859478965420033)]} 0 2
[junit4:junit4] 2> 730172 T1820 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[19 (1438859478970662912)]} 0 2
[junit4:junit4] 2> 730173 T1821 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10019 (1438859478971711488)]} 0 1
[junit4:junit4] 2> 730175 T1806 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[19 (1438859478970662912)]} 0 9
[junit4:junit4] 2> 730183 T1802 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10019 (1438859478971711488)]} 0 15
[junit4:junit4] 2> 730231 T1787 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[15 (-1438859479036723200)]} 0 1
[junit4:junit4] 2> 730238 T1782 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10015 (-1438859479045111808)]} 0 0
[junit4:junit4] 2> 730241 T1822 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[15 (-1438859479043014656)]} 0 0
[junit4:junit4] 2> 730243 T1804 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[15 (-1438859479043014656)]} 0 7
[junit4:junit4] 2> 730253 T1823 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10015 (-1438859479051403264)]} 0 0
[junit4:junit4] 2> 730256 T1785 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[20 (1438859479061889024)]} 0 2
[junit4:junit4] 2> 730257 T1804 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10015 (-1438859479051403264)]} 0 13
[junit4:junit4] 2> 730263 T1786 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10020 (1438859479070277632)]} 0 1
[junit4:junit4] 2> 730265 T1819 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[20 (1438859479068180480)]} 0 1
[junit4:junit4] 2> 730266 T1805 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[20 (1438859479068180480)]} 0 7
[junit4:junit4] 2> 730273 T1818 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10020 (1438859479076569088)]} 0 1
[junit4:junit4] 2> 730274 T1806 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10020 (1438859479076569088)]} 0 6
[junit4:junit4] 2> 730283 T1783 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[21 (1438859479091249152)]} 0 1
[junit4:junit4] 2> 730291 T1784 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10021 (1438859479099637760)]} 0 2
[junit4:junit4] 2> 730293 T1820 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[21 (1438859479096492032)]} 0 1
[junit4:junit4] 2> 730294 T1802 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[21 (1438859479096492032)]} 0 7
[junit4:junit4] 2> 730302 T1821 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10021 (1438859479105929216)]} 0 2
[junit4:junit4] 2> 730303 T1801 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10021 (1438859479105929216)]} 0 7
[junit4:junit4] 2> 730329 T1787 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[22 (1438859479137386496)]} 0 3
[junit4:junit4] 2> 730335 T1782 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10022 (1438859479145775104)]} 0 1
[junit4:junit4] 2> 730354 T1822 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[22 (1438859479159406592)]} 0 2
[junit4:junit4] 2> 730356 T1804 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[22 (1438859479159406592)]} 0 10
[junit4:junit4] 2> 730358 T1823 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10022 (1438859479161503744)]} 0 1
[junit4:junit4] 2> 730359 T1805 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10022 (1438859479161503744)]} 0 10
[junit4:junit4] 2> 730368 T1785 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[23 (1438859479180378112)]} 0 2
[junit4:junit4] 2> 730377 T1786 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10023 (1438859479189815296)]} 0 1
[junit4:junit4] 2> 730381 T1819 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[23 (1438859479186669568)]} 0 1
[junit4:junit4] 2> 730385 T1806 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[23 (1438859479186669568)]} 0 13
[junit4:junit4] 2> 730389 T1820 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10023 (1438859479197155328)]} 0 2
[junit4:junit4] 2> 730390 T1802 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10023 (1438859479197155328)]} 0 7
[junit4:junit4] 2> 730486 T1783 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[24 (1438859479303061504)]} 0 2
[junit4:junit4] 2> 730488 T1784 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10024 (1438859479303061505)]} 0 4
[junit4:junit4] 2> 730499 T1821 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10024 (1438859479312498688)]} 0 1
[junit4:junit4] 2> 730502 T1822 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[24 (1438859479315644416)]} 0 2
[junit4:junit4] 2> 730506 T1804 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[24 (1438859479315644416)]} 0 10
[junit4:junit4] 2> 730507 T1801 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10024 (1438859479312498688)]} 0 15
[junit4:junit4] 2> 730583 T1787 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10016 (-1438859479406870528)]} 0 1
[junit4:junit4] 2> 730584 T1782 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[16 (-1438859479407919104)]} 0 0
[junit4:junit4] 2> 730597 T1823 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10016 (-1438859479418404864)]} 0 0
[junit4:junit4] 2> 730602 T1819 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[16 (-1438859479418404865)]} 0 1
[junit4:junit4] 2> 730606 T1805 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10016 (-1438859479418404864)]} 0 12
[junit4:junit4] 2> 730609 T1806 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[16 (-1438859479418404865)]} 0 15
[junit4:junit4] 2> 730615 T1785 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10025 (1438859479439376384)]} 0 2
[junit4:junit4] 2> 730616 T1786 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[25 (1438859479439376385)]} 0 2
[junit4:junit4] 2> 730624 T1818 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10025 (1438859479444619264)]} 0 2
[junit4:junit4] 2> 730625 T1804 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10025 (1438859479444619264)]} 0 7
[junit4:junit4] 2> 730625 T1820 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[25 (1438859479445667840)]} 0 2
[junit4:junit4] 2> 730626 T1801 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[25 (1438859479445667840)]} 0 6
[junit4:junit4] 2> 730669 T1783 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10017 (-1438859479497048064)]} 0 1
[junit4:junit4] 2> 730669 T1782 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[17 (-1438859479497048065)]} 0 0
[junit4:junit4] 2> 730679 T1822 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[17 (-1438859479503339520)]} 0 0
[junit4:junit4] 2> 730680 T1822 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10017 (-1438859479502290944)]} 0 0
[junit4:junit4] 2> 730681 T1805 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[17 (-1438859479503339520)]} 0 7
[junit4:junit4] 2> 730681 T1802 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10017 (-1438859479502290944)]} 0 7
[junit4:junit4] 2> 730686 T1787 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[26 (1438859479513825280)]} 0 2
[junit4:junit4] 2> 730687 T1785 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10026 (1438859479513825281)]} 0 2
[junit4:junit4] 2> 730694 T1819 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[26 (1438859479518019584)]} 0 1
[junit4:junit4] 2> 730695 T1806 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[26 (1438859479518019584)]} 0 6
[junit4:junit4] 2> 730696 T1823 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10026 (1438859479519068160)]} 0 2
[junit4:junit4] 2> 730697 T1804 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10026 (1438859479519068160)]} 0 7
[junit4:junit4] 2> 730796 T1786 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[27 (1438859479628120064)]} 0 2
[junit4:junit4] 2> 730804 T1786 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10027 (1438859479636508672)]} 0 3
[junit4:junit4] 2> 730810 T1818 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[27 (1438859479638605824)]} 0 1
[junit4:junit4] 2> 730812 T1801 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[27 (1438859479638605824)]} 0 8
[junit4:junit4] 2> 730812 T1821 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10027 (1438859479642800128)]} 0 1
[junit4:junit4] 2> 730813 T1805 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10027 (1438859479642800128)]} 0 5
[junit4:junit4] 2> 730842 T1783 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[18 (-1438859479677403136)]} 0 1
[junit4:junit4] 2> 730843 T1782 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10018 (-1438859479679500288)]} 0 0
[junit4:junit4] 2> 730854 T1822 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[18 (-1438859479685791744)]} 0 0
[junit4:junit4] 2> 730855 T1822 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10018 (-1438859479687888896)]} 0 0
[junit4:junit4] 2> 730856 T1806 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10018 (-1438859479687888896)]} 0 5
[junit4:junit4] 2> 730857 T1802 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[18 (-1438859479685791744)]} 0 8
[junit4:junit4] 2> 730860 T1787 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10028 (1438859479696277504)]} 0 1
[junit4:junit4] 2> 730861 T1785 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[28 (1438859479697326080)]} 0 1
[junit4:junit4] 2> 730865 T1803 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 3, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 730866 T1803 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=3&state=recovering&nodeName=127.0.0.1:49652_e_ro%252Fm&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2004
[junit4:junit4] 2> 730868 T1769 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 49652
[junit4:junit4] 2> 730869 T1769 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=2123053172
[junit4:junit4] 2> 730875 T1823 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10028 (1438859479701520384)]} 0 2
[junit4:junit4] 2> 730876 T1804 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10028 (1438859479701520384)]} 0 12
[junit4:junit4] 2> 730876 T1820 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[28 (1438859479704666112)]} 0 3
[junit4:junit4] 2> 730877 T1803 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[28 (1438859479704666112)]} 0 10
[junit4:junit4] 2> 730890 T1784 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10029 (1438859479727734784)]} 0 2
[junit4:junit4] 2> 730891 T1786 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[29 (1438859479727734785)]} 0 2
[junit4:junit4] 2> 730898 T1818 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10029 (1438859479732977664)]} 0 1
[junit4:junit4] 2> 730899 T1821 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[29 (1438859479732977665)]} 0 1
[junit4:junit4] 2> 730900 T1806 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10029 (1438859479732977664)]} 0 7
[junit4:junit4] 2> 730901 T1802 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[29 (1438859479732977665)]} 0 7
[junit4:junit4] 2> 730975 T1783 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10020 (-1438859479817912320)]} 0 0
[junit4:junit4] 2> 730978 T1782 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[20 (-1438859479820009472)]} 0 1
[junit4:junit4] 2> 730983 T1822 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10020 (-1438859479823155200)]} 0 1
[junit4:junit4] 2> 730985 T1819 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[20 (-1438859479825252352)]} 0 1
[junit4:junit4] 2> 730985 T1801 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10020 (-1438859479823155200)]} 0 5
[junit4:junit4] 2> 730986 T1805 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[20 (-1438859479825252352)]} 0 5
[junit4:junit4] 2> 730990 T1787 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10030 (1438859479832592384)]} 0 1
[junit4:junit4] 2> 730991 T1785 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[30 (1438859479832592385)]} 0 2
[junit4:junit4] 2> 730998 T1823 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10030 (1438859479836786688)]} 0 1
[junit4:junit4] 2> 731000 T1823 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[30 (1438859479837835264)]} 0 1
[junit4:junit4] 2> 731001 T1804 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10030 (1438859479836786688)]} 0 8
[junit4:junit4] 2> 731001 T1803 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[30 (1438859479837835264)]} 0 7
[junit4:junit4] 2> 731030 T1784 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10027 (-1438859479875584000)]} 0 1
[junit4:junit4] 2> 731033 T1784 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[27 (-1438859479878729728)]} 0 1
[junit4:junit4] 2> 731048 T1818 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10027 (-1438859479888166912)]} 0 1
[junit4:junit4] 2> 731049 T1821 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[27 (-1438859479888166913)]} 0 1
[junit4:junit4] 2> 731051 T1802 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10027 (-1438859479888166912)]} 0 9
[junit4:junit4] 2> 731052 T1801 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[27 (-1438859479888166913)]} 0 10
[junit4:junit4] 2> 731056 T1783 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10031 (1438859479901798400)]} 0 2
[junit4:junit4] 2> 731057 T1782 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[31 (1438859479901798401)]} 0 2
[junit4:junit4] 2> 731066 T1822 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10031 (1438859479905992704)]} 0 3
[junit4:junit4] 2> 731067 T1805 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10031 (1438859479905992704)]} 0 8
[junit4:junit4] 2> 731069 T1819 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[31 (1438859479907041280)]} 0 2
[junit4:junit4] 2> 731072 T1806 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[31 (1438859479907041280)]} 0 12
[junit4:junit4] 2> 731113 T1787 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10031 (-1438859479962615808)]} 0 0
[junit4:junit4] 2> 731118 T1784 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[31 (-1438859479966810112)]} 0 1
[junit4:junit4] 2> 731120 T1823 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10031 (-1438859479966810112)]} 0 0
[junit4:junit4] 2> 731121 T1804 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10031 (-1438859479966810112)]} 0 4
[junit4:junit4] 2> 731124 T1820 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[31 (-1438859479971004416)]} 0 1
[junit4:junit4] 2> 731125 T1803 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[31 (-1438859479971004416)]} 0 5
[junit4:junit4] 2> 731125 T1786 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10032 (1438859479974150144)]} 0 1
[junit4:junit4] 2> 731131 T1783 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[32 (1438859479980441600)]} 0 2
[junit4:junit4] 2> 731136 T1818 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10032 (1438859479981490176)]} 0 1
[junit4:junit4] 2> 731137 T1802 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10032 (1438859479981490176)]} 0 7
[junit4:junit4] 2> 731140 T1821 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[32 (1438859479985684480)]} 0 2
[junit4:junit4] 2> 731141 T1801 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[32 (1438859479985684480)]} 0 6
[junit4:junit4] 2> 731190 T1782 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10033 (1438859480041259008)]} 0 2
[junit4:junit4] 2> 731191 T1785 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[33 (1438859480041259009)]} 0 3
[junit4:junit4] 2> 731211 T1822 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10033 (1438859480049647616)]} 0 4
[junit4:junit4] 2> 731212 T1805 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10033 (1438859480049647616)]} 0 16
[junit4:junit4] 2> 731212 T1819 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[33 (1438859480056987648)]} 0 1
[junit4:junit4] 2> 731214 T1806 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[33 (1438859480056987648)]} 0 12
[junit4:junit4] 2> 731293 T1787 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10033 (-1438859480151359488)]} 0 0
[junit4:junit4] 2> 731294 T1784 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[33 (-1438859480152408064)]} 0 0
[junit4:junit4] 2> 731305 T1820 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10033 (-1438859480160796672)]} 0 1
[junit4:junit4] 2> 731305 T1818 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[33 (-1438859480160796673)]} 0 0
[junit4:junit4] 2> 731306 T1803 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10033 (-1438859480160796672)]} 0 4
[junit4:junit4] 2> 731307 T1804 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[33 (-1438859480160796673)]} 0 5
[junit4:junit4] 2> 731311 T1786 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10034 (1438859480168136704)]} 0 2
[junit4:junit4] 2> 731312 T1783 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[34 (1438859480170233856)]} 0 2
[junit4:junit4] 2> 731319 T1821 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10034 (1438859480173379584)]} 0 1
[junit4:junit4] 2> 731320 T1822 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[34 (1438859480174428160)]} 0 2
[junit4:junit4] 2> 731320 T1802 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10034 (1438859480173379584)]} 0 6
[junit4:junit4] 2> 731321 T1801 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[34 (1438859480174428160)]} 0 6
[junit4:junit4] 2> 731378 T1782 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10034 (-1438859480239439872)]} 0 2
[junit4:junit4] 2> 731378 T1785 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[34 (-1438859480240488448)]} 0 0
[junit4:junit4] 2> 731384 T1823 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[10034 (-1438859480244682752)]} 0 0
[junit4:junit4] 2> 731386 T1805 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10034 (-1438859480244682752)]} 0 4
[junit4:junit4] 2> 731386 T1819 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {delete=[34 (-1438859480244682753)]} 0 1
[junit4:junit4] 2> 731387 T1806 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[34 (-1438859480244682753)]} 0 5
[junit4:junit4] 2> 731391 T1787 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10035 (1438859480253071360)]} 0 2
[junit4:junit4] 2> 731392 T1784 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[35 (1438859480254119936)]} 0 1
[junit4:junit4] 2> 731405 T1820 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10035 (1438859480257265664)]} 0 2
[junit4:junit4] 2> 731406 T1818 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[35 (1438859480264605696)]} 0 2
[junit4:junit4] 2> 731406 T1803 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10035 (1438859480257265664)]} 0 12
[junit4:junit4] 2> 731407 T1804 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[35 (1438859480264605696)]} 0 6
[junit4:junit4] 2> 731466 T1786 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10036 (1438859480331714560)]} 0 2
[junit4:junit4] 2> 731467 T1783 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[36 (1438859480331714561)]} 0 2
[junit4:junit4] 2> 731474 T1821 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10036 (1438859480336957440)]} 0 1
[junit4:junit4] 2> 731475 T1822 C1586 P49652 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={distrib.from=http://127.0.0.1:49649/e_ro/m/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[36 (1438859480336957441)]} 0 1
[junit4:junit4] 2> 731475 T1801 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10036 (1438859480336957440)]} 0 6
[junit4:junit4] 2> 731476 T1805 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[36 (1438859480336957441)]} 0 6
[junit4:junit4] 2> 731533 T1792 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 731535 T1792 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:49652_e_ro%2Fm",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49652/e_ro/m"}
[junit4:junit4] 2> 731545 T1798 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> 731546 T1811 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> 731547 T1827 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> 731547 T1791 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> 731581 T1782 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[37 (1438859480451252224)]} 0 2
[junit4:junit4] 2> 731583 T1785 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10037 (1438859480452300800)]} 0 4
[junit4:junit4] 2> 731591 T1806 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[37 (1438859480461737984)]} 0 2
[junit4:junit4] 2> 731592 T1802 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10037 (1438859480463835136)]} 0 2
[junit4:junit4] 2> 731695 T1784 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[35 (-1438859480572887040)]} 0 0
[junit4:junit4] 2> 731697 T1786 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10035 (-1438859480574984192)]} 0 0
[junit4:junit4] 2> 731701 T1803 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[35 (-1438859480578129920)]} 0 1
[junit4:junit4] 2> 731702 T1804 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10035 (-1438859480579178496)]} 0 1
[junit4:junit4] 2> 731709 T1783 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[38 (1438859480585469952)]} 0 3
[junit4:junit4] 2> 731713 T1782 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10038 (1438859480590712832)]} 0 1
[junit4:junit4] 2> 731717 T1801 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[38 (1438859480595955712)]} 0 1
[junit4:junit4] 2> 731720 T1805 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10038 (1438859480598052864)]} 0 1
[junit4:junit4] 2> 731781 T1787 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[39 (1438859480662016000)]} 0 2
[junit4:junit4] 2> 731786 T1785 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10039 (1438859480667258880)]} 0 1
[junit4:junit4] 2> 731790 T1806 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[39 (1438859480671453184)]} 0 1
[junit4:junit4] 2> 731793 T1802 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10039 (1438859480674598912)]} 0 1
[junit4:junit4] 2> 731844 T1784 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[40 (1438859480724930560)]} 0 6
[junit4:junit4] 2> 731846 T1786 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10040 (1438859480725979136)]} 0 6
[junit4:junit4] 2> 731852 T1803 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[40 (1438859480736464896)]} 0 1
[junit4:junit4] 2> 731854 T1803 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10040 (1438859480738562048)]} 0 1
[junit4:junit4] 2> 731878 T1783 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10039 (-1438859480764776448)]} 0 0
[junit4:junit4] 2> 731878 T1782 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[39 (-1438859480764776449)]} 0 0
[junit4:junit4] 2> 731882 T1805 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10039 (-1438859480767922176)]} 0 1
[junit4:junit4] 2> 731882 T1806 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[39 (-1438859480768970752)]} 0 0
[junit4:junit4] 2> 731886 T1787 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10041 (1438859480772116480)]} 0 1
[junit4:junit4] 2> 731887 T1785 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[41 (1438859480773165056)]} 0 2
[junit4:junit4] 2> 731890 T1802 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10041 (1438859480776310784)]} 0 1
[junit4:junit4] 2> 731895 T1804 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[41 (1438859480778407936)]} 0 4
[junit4:junit4] 2> 731916 T1784 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10041 (-1438859480804622336)]} 0 1
[junit4:junit4] 2> 731922 T1803 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10041 (-1438859480809865216)]} 0 0
[junit4:junit4] 2> 731925 T1786 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[41 (-1438859480814059520)]} 0 1
[junit4:junit4] 2> 731929 T1783 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10042 (1438859480815108096)]} 0 3
[junit4:junit4] 2> 731936 T1801 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[41 (-1438859480824545280)]} 0 1
[junit4:junit4] 2> 731938 T1805 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10042 (1438859480826642432)]} 0 1
[junit4:junit4] 2> 731940 T1782 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[42 (1438859480828739584)]} 0 1
[junit4:junit4] 2> 731946 T1806 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[42 (1438859480835031040)]} 0 1
[junit4:junit4] 2> 731955 T1787 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10042 (-1438859480845516800)]} 0 1
[junit4:junit4] 2> 731958 T1802 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10042 (-1438859480848662528)]} 0 1
[junit4:junit4] 2> 731962 T1785 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10043 (1438859480851808256)]} 0 1
[junit4:junit4] 2> 731963 T1784 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[42 (-1438859480853905408)]} 0 0
[junit4:junit4] 2> 731966 T1804 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10043 (1438859480856002560)]} 0 1
[junit4:junit4] 2> 731968 T1803 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[42 (-1438859480859148288)]} 0 0
[junit4:junit4] 2> 731972 T1786 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[43 (1438859480862294016)]} 0 1
[junit4:junit4] 2> 731976 T1801 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[43 (1438859480867536896)]} 0 1
[junit4:junit4] 2> 732021 T1783 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10044 (1438859480912625664)]} 0 2
[junit4:junit4] 2> 732025 T1805 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10044 (1438859480917868544)]} 0 1
[junit4:junit4] 2> 732035 T1787 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[44 (1438859480923111424)]} 0 6
[junit4:junit4] 2> 732042 T1806 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[44 (1438859480935694336)]} 0 2
[junit4:junit4] 2> 732094 T1785 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10045 (1438859480990220288)]} 0 2
[junit4:junit4] 2> 732105 T1802 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10045 (1438859481001754624)]} 0 2
[junit4:junit4] 2> 732111 T1784 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[45 (1438859481008046080)]} 0 2
[junit4:junit4] 2> 732118 T1804 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[45 (1438859481015386112)]} 0 1
[junit4:junit4] 2> 732137 T1786 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10045 (-1438859481036357632)]} 0 0
[junit4:junit4] 2> 732141 T1803 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10045 (-1438859481040551936)]} 0 0
[junit4:junit4] 2> 732146 T1782 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10046 (1438859481044746240)]} 0 1
[junit4:junit4] 2> 732151 T1783 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[45 (-1438859481051037696)]} 0 1
[junit4:junit4] 2> 732153 T1801 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10046 (1438859481052086272)]} 0 1
[junit4:junit4] 2> 732156 T1805 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[45 (-1438859481056280576)]} 0 0
[junit4:junit4] 2> 732161 T1787 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[46 (1438859481060474880)]} 0 1
[junit4:junit4] 2> 732165 T1806 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[46 (1438859481064669184)]} 0 1
[junit4:junit4] 2> 732221 T1785 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10047 (1438859481123389440)]} 0 2
[junit4:junit4] 2> 732225 T1802 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10047 (1438859481127583744)]} 0 1
[junit4:junit4] 2> 732233 T1784 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[47 (1438859481135972352)]} 0 2
[junit4:junit4] 2> 732242 T1804 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[47 (1438859481145409536)]} 0 1
[junit4:junit4] 2> 732264 T1786 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10046 (-1438859481168478208)]} 0 1
[junit4:junit4] 2> 732269 T1803 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10046 (-1438859481174769664)]} 0 1
[junit4:junit4] 2> 732274 T1782 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10048 (1438859481178963968)]} 0 1
[junit4:junit4] 2> 732278 T1805 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10048 (1438859481183158272)]} 0 1
[junit4:junit4] 2> 732283 T1783 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[46 (-1438859481188401152)]} 0 1
[junit4:junit4] 2> 732286 T1806 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[46 (-1438859481192595456)]} 0 0
[junit4:junit4] 2> 732290 T1787 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[48 (1438859481195741184)]} 0 1
[junit4:junit4] 2> 732294 T1802 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[48 (1438859481199935488)]} 0 1
[junit4:junit4] 2> 732327 T1785 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10049 (1438859481231392768)]} 0 4
[junit4:junit4] 2> 732337 T1784 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[49 (1438859481243975680)]} 0 2
[junit4:junit4] 2> 732339 T1804 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10049 (1438859481247121408)]} 0 1
[junit4:junit4] 2> 732344 T1801 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[49 (1438859481252364288)]} 0 1
[junit4:junit4] 2> 732437 T1786 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10047 (-1438859481349881856)]} 0 1
[junit4:junit4] 2> 732440 T1803 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10047 (-1438859481354076160)]} 0 0
[junit4:junit4] 2> 732440 T1783 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[47 (-1438859481354076160)]} 0 0
[junit4:junit4] 2> 732445 T1787 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10050 (1438859481358270464)]} 0 1
[junit4:junit4] 2> 732447 T1805 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[47 (-1438859481361416192)]} 0 0
[junit4:junit4] 2> 732449 T1806 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10050 (1438859481363513344)]} 0 1
[junit4:junit4] 2> 732452 T1785 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[50 (1438859481365610496)]} 0 1
[junit4:junit4] 2> 732464 T1802 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[50 (1438859481377144832)]} 0 2
[junit4:junit4] 2> 732508 T1784 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10048 (-1438859481425379328)]} 0 1
[junit4:junit4] 2> 732512 T1804 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10048 (-1438859481429573632)]} 0 0
[junit4:junit4] 2> 732516 T1782 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10051 (1438859481432719360)]} 0 1
[junit4:junit4] 2> 732521 T1801 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10051 (1438859481437962240)]} 0 2
[junit4:junit4] 2> 732523 T1786 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[48 (-1438859481441107968)]} 0 0
[junit4:junit4] 2> 732527 T1803 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[48 (-1438859481444253696)]} 0 1
[junit4:junit4] 2> 732531 T1783 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[51 (1438859481448448000)]} 0 2
[junit4:junit4] 2> 732535 T1805 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[51 (1438859481452642304)]} 0 1
[junit4:junit4] 2> 732586 T1787 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10052 (1438859481505071104)]} 0 2
[junit4:junit4] 2> 732591 T1806 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10052 (1438859481511362560)]} 0 2
[junit4:junit4] 2> 732598 T1785 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[52 (1438859481518702592)]} 0 2
[junit4:junit4] 2> 732602 T1802 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[52 (1438859481522896896)]} 0 1
[junit4:junit4] 2> 732675 T1784 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10053 (1438859481598394368)]} 0 2
[junit4:junit4] 2> 732686 T1804 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10053 (1438859481609928704)]} 0 2
[junit4:junit4] 2> 732686 T1782 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[53 (1438859481610977280)]} 0 2
[junit4:junit4] 2> 732694 T1803 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[53 (1438859481619365888)]} 0 2
[junit4:junit4] 2> 732732 T1786 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10049 (-1438859481660260352)]} 0 1
[junit4:junit4] 2> 732736 T1805 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10049 (-1438859481664454656)]} 0 0
[junit4:junit4] 2> 732737 T1783 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[49 (-1438859481665503232)]} 0 1
[junit4:junit4] 2> 732741 T1806 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[49 (-1438859481669697536)]} 0 1
[junit4:junit4] 2> 732741 T1787 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10054 (1438859481668648960)]} 0 1
[junit4:junit4] 2> 732751 T1785 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[54 (1438859481677037568)]} 0 4
[junit4:junit4] 2> 732754 T1802 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10054 (1438859481682280448)]} 0 2
[junit4:junit4] 2> 732756 T1801 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[54 (1438859481685426176)]} 0 1
[junit4:junit4] 2> 732853 T1784 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10055 (1438859481786089472)]} 0 2
[junit4:junit4] 2> 732854 T1786 C1584 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[55 (1438859481786089473)]} 0 2
[junit4:junit4] 2> 732858 T1804 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10055 (1438859481791332352)]} 0 1
[junit4:junit4] 2> 732859 T1803 C1585 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[55 (1438859481792380928)]} 0 1
[junit4:junit4] 2> C1586_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=down, core=collection1, collection=collection1, node_name=127.0.0.1:49652_e_ro%2Fm, base_url=http://127.0.0.1:49652/e_ro/m}
[junit4:junit4] 2> 732871 T1830 C1586 P49652 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:49649/e_ro/m/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 732871 T1830 C1586 P49652 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:49652/e_ro/m START replicas=[http://127.0.0.1:49649/e_ro/m/collection1/] nUpdates=100
[junit4:junit4] 2> 732872 T1830 C1586 P49652 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 732873 T1830 C1586 P49652 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 732874 T1830 C1586 P49652 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 732874 T1830 C1586 P49652 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 732874 T1830 C1586 P49652 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=tlog{file=./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty2/tlog/tlog.0000000000000000000 refcount=1}}
[junit4:junit4] 2> 732874 T1830 C1586 P49652 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:49649/e_ro/m/collection1/. core=collection1
[junit4:junit4] 2> 732875 T1830 C1586 P49652 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 732883 T1769 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 732897 T1769 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> ASYNC NEW_CORE C1587 name=collection1 org.apache.solr.core.SolrCore@7bf91eea url=http://127.0.0.1:49649/e_ro/m/collection1 node=127.0.0.1:49649_e_ro%2Fm C1587_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:49649_e_ro%2Fm, base_url=http://127.0.0.1:49649/e_ro/m, leader=true}
[junit4:junit4] 2> 732912 T1805 C1587 P49649 oasc.SolrCore.execute [collection1] webapp=/e_ro/m path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 732915 T1769 oasc.RecoveryStrategy.close WARN Stopping recovery for zkNodeName=3core=collection1
[junit4:junit4] 2> 732916 T1806 C1587 P49649 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> ASYNC NEW_CORE C1588 name=collection1 org.apache.solr.core.SolrCore@1a7ce791 url=http://127.0.0.1:49645/e_ro/m/collection1 node=127.0.0.1:49645_e_ro%2Fm C1588_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:49645_e_ro%2Fm, base_url=http://127.0.0.1:49645/e_ro/m, leader=true}
[junit4:junit4] 2> 732936 T1783 C1588 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10050 (-1438859481874169856)]} 0 0
[junit4:junit4] 2> 732937 T1787 C1588 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[50 (-1438859481874169857)]} 0 1
[junit4:junit4] 2> 732942 T1802 C1587 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10050 (-1438859481878364160)]} 0 2
[junit4:junit4] 2> 732943 T1802 C1587 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[50 (-1438859481880461312)]} 0 1
[junit4:junit4] 2> 732949 T1785 C1588 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10056 (1438859481883607040)]} 0 5
[junit4:junit4] 2> 732951 T1782 C1588 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[56 (1438859481888849920)]} 0 1
[junit4:junit4] 2> 732956 T1804 C1587 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10056 (1438859481891995648)]} 0 3
[junit4:junit4] 2> 732957 T1803 C1587 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[56 (1438859481895141376)]} 0 2
[junit4:junit4] 2> 732960 T1806 C1587 P49649 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6b948d26 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7734f6ba),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6b948d26 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7734f6ba),segFN=segments_2,generation=2}
[junit4:junit4] 2> 732960 T1806 C1587 P49649 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 733027 T1786 C1588 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[57 (1438859481968541697)]} 0 2
[junit4:junit4] 2> 733028 T1784 C1588 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10057 (1438859481968541696)]} 0 3
[junit4:junit4] 2> 733033 T1805 C1587 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[57 (1438859481973784576)]} 0 2
[junit4:junit4] 2> 733034 T1802 C1587 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10057 (1438859481974833152)]} 0 2
[junit4:junit4] 2> 733045 T1806 C1587 P49649 oass.SolrIndexSearcher.<init> Opening Searcher@107433b7 realtime
[junit4:junit4] 2> 733050 T1806 C1587 P49649 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 733051 T1806 C1587 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 135
[junit4:junit4] 2> ASYNC NEW_CORE C1589 name=collection1 org.apache.solr.core.SolrCore@53198fc9 url=http://127.0.0.1:49652/e_ro/m/collection1 node=127.0.0.1:49652_e_ro%2Fm C1589_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=down, core=collection1, collection=collection1, node_name=127.0.0.1:49652_e_ro%2Fm, base_url=http://127.0.0.1:49652/e_ro/m}
[junit4:junit4] 2> 733052 T1830 C1589 P49652 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 733053 T1830 C1589 P49652 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 733056 T1804 C1587 P49649 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 733057 T1804 C1587 P49649 oasc.SolrCore.execute [collection1] webapp=/e_ro/m path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=2
[junit4:junit4] 2> 733059 T1830 C1589 P49652 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 733059 T1830 C1589 P49652 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 733059 T1830 C1589 P49652 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 733064 T1792 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 733064 T1803 C1587 P49649 oasc.SolrCore.execute [collection1] webapp=/e_ro/m path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=1
[junit4:junit4] 2> 733066 T1830 C1589 P49652 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 5
[junit4:junit4] 2> 733066 T1792 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:49652_e_ro%2Fm",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49652/e_ro/m"}
[junit4:junit4] 2> 733066 T1830 C1589 P49652 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty2/index.20130625173532911
[junit4:junit4] 2> 733067 T1830 C1589 P49652 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@cb689da lockFactory=org.apache.lucene.store.NativeFSLockFactory@3fca7751) fullCopy=false
[junit4:junit4] 2> 733072 T1805 C1587 P49649 oasc.SolrCore.execute [collection1] webapp=/e_ro/m path=/replication params={file=_0.cfs&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 733079 T1802 C1587 P49649 oasc.SolrCore.execute [collection1] webapp=/e_ro/m path=/replication params={file=_0.cfe&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 733082 T1827 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> 733082 T1811 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> 733082 T1791 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> 733082 T1798 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> 733095 T1801 C1587 P49649 oasc.SolrCore.execute [collection1] webapp=/e_ro/m path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=1
[junit4:junit4] 2> 733099 T1804 C1587 P49649 oasc.SolrCore.execute [collection1] webapp=/e_ro/m path=/replication params={file=_0_1.del&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 733104 T1803 C1587 P49649 oasc.SolrCore.execute [collection1] webapp=/e_ro/m path=/replication params={file=_0.si&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 733105 T1830 C1589 P49652 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 733106 T1830 C1589 P49652 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 733107 T1830 C1589 P49652 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 733107 T1830 C1589 P49652 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4:junit4] 2> 733119 T1830 C1589 P49652 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1d5189b8 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2b54966c),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1d5189b8 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2b54966c),segFN=segments_2,generation=2}
[junit4:junit4] 2> 733120 T1830 C1589 P49652 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 733123 T1830 C1589 P49652 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1d5189b8 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2b54966c),segFN=segments_2,generation=2}
[junit4:junit4] 2> 733124 T1830 C1589 P49652 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 733124 T1830 C1589 P49652 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 733133 T1830 C1589 P49652 oass.SolrIndexSearcher.<init> Opening Searcher@5f93887 main
[junit4:junit4] 2> 733135 T1829 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5f93887 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):c38/12)}
[junit4:junit4] 2> 733135 T1783 C1588 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[58 (1438859482081787904)]} 0 1
[junit4:junit4] 2> 733138 T1783 C1588 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10058 (1438859482083885056)]} 0 2
[junit4:junit4] 2> 733138 T1830 C1589 P49652 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty2/index.20130625173532911 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty2/index.20130625173532911;done=true>>]
[junit4:junit4] 2> 733140 T1830 C1589 P49652 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty2/index.20130625173532911
[junit4:junit4] 2> 733140 T1830 C1589 P49652 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty2/index.20130625173532911
[junit4:junit4] 2> 733141 T1805 C1587 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[58 (1438859482088079360)]} 0 1
[junit4:junit4] 2> 733143 T1805 C1587 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10058 (1438859482090176512)]} 0 1
[junit4:junit4] 2> 733147 T1830 C1589 P49652 oasc.RecoveryStrategy.replay Replaying buffered documents. core=collection1
[junit4:junit4] 2> 733148 T1838 C1589 P49652 oasu.UpdateLog$LogReplayer.doReplay WARN Starting log replay tlog{file=./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty2/tlog/tlog.0000000000000000000 refcount=2} active=true starting pos=5606
[junit4:junit4] 2> 733153 T1838 C1589 P49652 oasu.DirectUpdateHandler2.commit start commit{flags=2,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 733155 T1838 C1589 P49652 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1d5189b8 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2b54966c),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1d5189b8 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2b54966c),segFN=segments_3,generation=3}
[junit4:junit4] 2> 733155 T1838 C1589 P49652 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 733156 T1838 C1589 P49652 oass.SolrIndexSearcher.<init> Opening Searcher@67d68f53 main
[junit4:junit4] 2> 733156 T1838 C1589 P49652 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 733157 T1829 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@67d68f53 main{StandardDirectoryReader(segments_2:3:nrt _0(5.0):c38/12)}
[junit4:junit4] 2> 733158 T1838 C1589 P49652 oasup.LogUpdateProcessor.finish [collection1] {} 0 10
[junit4:junit4] 2> 733159 T1838 C1589 P49652 oasu.UpdateLog$LogReplayer.run WARN Log replay finished. recoveryInfo=RecoveryInfo{adds=0 deletes=0 deleteByQuery=0 errors=0 positionOfStart=5606}
[junit4:junit4] 2> 733159 T1830 C1589 P49652 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 733159 T1830 C1589 P49652 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 733160 T1830 C1589 P49652 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 733162 T1830 C1589 P49652 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 733163 T1769 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@53198fc9
[junit4:junit4] 2> 733174 T1769 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=38,cumulative_deletesById=22,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 733175 T1769 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 733176 T1769 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 733176 T1769 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 733179 T1769 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 733180 T1769 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 733180 T1769 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty2 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty2;done=false>>]
[junit4:junit4] 2> 733180 T1769 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty2
[junit4:junit4] 2> 733181 T1769 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty2/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty2/index;done=false>>]
[junit4:junit4] 2> 733181 T1769 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty2/index
[junit4:junit4] 2> 733186 T1811 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> 733189 T1798 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 733189 T1798 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> 733191 T1791 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 733191 T1791 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> 733194 T1811 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 733200 T1769 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/e_ro/m,null}
[junit4:junit4] 2> 733232 T1785 C1588 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[51 (-1438859482184548352)]} 0 1
[junit4:junit4] 2> 733233 T1782 C1588 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10051 (-1438859482185596928)]} 0 0
[junit4:junit4] 2> 733237 T1806 C1587 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[51 (-1438859482189791232)]} 0 0
[junit4:junit4] 2> 733237 T1801 C1587 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10051 (-1438859482189791233)]} 0 0
[junit4:junit4] 2> 733242 T1786 C1588 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[59 (1438859482193985536)]} 0 1
[junit4:junit4] 2> 733243 T1784 C1588 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10059 (1438859482193985537)]} 0 2
[junit4:junit4] 2> 733246 T1804 C1587 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[59 (1438859482198179840)]} 0 1
[junit4:junit4] 2> 733248 T1803 C1587 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10059 (1438859482201325568)]} 0 1
[junit4:junit4] 2> 733361 T1787 C1588 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[60 (1438859482315620352)]} 0 5
[junit4:junit4] 2> 733363 T1785 C1588 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10060 (1438859482316668928)]} 0 5
[junit4:junit4] 2> 733371 T1805 C1587 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[60 (1438859482328203264)]} 0 3
[junit4:junit4] 2> 733373 T1802 C1587 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10060 (1438859482331348992)]} 0 1
[junit4:junit4] 2> 733386 T1782 C1588 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[55 (-1438859482344980480)]} 0 1
[junit4:junit4] 2> 733387 T1782 C1588 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10055 (-1438859482347077632)]} 0 0
[junit4:junit4] 2> 733389 T1801 C1587 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[55 (-1438859482349174784)]} 0 0
[junit4:junit4] 2> 733391 T1806 C1587 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10055 (-1438859482351271936)]} 0 1
[junit4:junit4] 2> 733394 T1784 C1588 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[61 (1438859482352320512)]} 0 2
[junit4:junit4] 2> 733397 T1783 C1588 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10061 (1438859482356514816)]} 0 2
[junit4:junit4] 2> 733399 T1804 C1587 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[61 (1438859482358611968)]} 0 1
[junit4:junit4] 2> 733401 T1803 C1587 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10061 (1438859482360709120)]} 0 1
[junit4:junit4] 2> 733442 T1787 C1588 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[62 (1438859482403700736)]} 0 2
[junit4:junit4] 2> 733445 T1787 C1588 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10062 (1438859482405797888)]} 0 2
[junit4:junit4] 2> 733448 T1805 C1587 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[62 (1438859482408943616)]} 0 2
[junit4:junit4] 2> 733450 T1802 C1587 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10062 (1438859482412089344)]} 0 1
[junit4:junit4] 2> 733455 T1769 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 733461 T1769 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:49652
[junit4:junit4] 2> 733462 T1769 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 733462 T1769 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 733463 T1769 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1372203323781
[junit4:junit4] 2> 733463 T1769 oasc.CoreContainer$Initializer.initialize looking for solr config file: /Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1372203323781/solr.xml
[junit4:junit4] 2> 733463 T1769 oasc.CoreContainer.<init> New CoreContainer 1722172963
[junit4:junit4] 2> 733465 T1769 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1372203323781/'
[junit4:junit4] 2> 733465 T1769 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build/solr-core/test/J0/./org.apache.solr.cloud.RecoveryZkTest-jetty2-1372203323781/'
[junit4:junit4] 2> 733552 T1786 C1588 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[57 (-1438859482520092672)]} 0 1
[junit4:junit4] 2> 733554 T1782 C1588 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10057 (-1438859482522189824)]} 0 0
[junit4:junit4] 2> 733556 T1801 C1587 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[57 (-1438859482524286976)]} 0 1
[junit4:junit4] 2> 733558 T1804 C1587 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10057 (-1438859482526384128)]} 0 1
[junit4:junit4] 2> 733560 T1784 C1588 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[63 (1438859482527432704)]} 0 1
[junit4:junit4] 2> 733565 T1783 C1588 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10063 (1438859482531627008)]} 0 3
[junit4:junit4] 2> 733566 T1803 C1587 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[63 (1438859482533724160)]} 0 1
[junit4:junit4] 2> ASYNC NEW_CORE C1590 name=collection1 org.apache.solr.core.SolrCore@7bf91eea url=http://127.0.0.1:49649/e_ro/m/collection1 node=127.0.0.1:49649_e_ro%2Fm C1590_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:49649_e_ro%2Fm, base_url=http://127.0.0.1:49649/e_ro/m, leader=true}
[junit4:junit4] 2> 733589 T1805 C1590 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10063 (1438859482556792832)]} 0 1
[junit4:junit4] 2> ASYNC NEW_CORE C1591 name=collection1 org.apache.solr.core.SolrCore@1a7ce791 url=http://127.0.0.1:49645/e_ro/m/collection1 node=127.0.0.1:49645_e_ro%2Fm C1591_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:49645_e_ro%2Fm, base_url=http://127.0.0.1:49645/e_ro/m, leader=true}
[junit4:junit4] 2> 733628 T1787 C1591 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[64 (1438859482597687296)]} 0 2
[junit4:junit4] 2> 733639 T1802 C1590 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[64 (1438859482610270208)]} 0 2
[junit4:junit4] 2> 733642 T1769 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 733642 T1769 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 733643 T1769 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 733643 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 733644 T1769 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 733644 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 733644 T1769 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 733645 T1769 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 733645 T1769 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 733646 T1769 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 733669 T1785 C1591 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10064 (1438859482635436032)]} 0 8
[junit4:junit4] 2> 733670 T1786 C1591 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[65 (1438859482642776064)]} 0 1
[junit4:junit4] 2> 733675 T1801 C1590 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10064 (1438859482648018944)]} 0 2
[junit4:junit4] 2> 733684 T1769 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 733684 T1769 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:49642/solr
[junit4:junit4] 2> 733685 T1769 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 733685 T1806 C1590 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[65 (1438859482658504704)]} 0 1
[junit4:junit4] 2> 733694 T1769 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 733695 T1849 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@283c035 name:ZooKeeperConnection Watcher:127.0.0.1:49642 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 733697 T1782 C1591 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10065 (1438859482671087616)]} 0 2
[junit4:junit4] 2> 733698 T1769 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 733701 T1804 C1590 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10065 (1438859482675281920)]} 0 1
[junit4:junit4] 2> 733727 T1784 C1591 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[60 (-1438859482702544896)]} 0 1
[junit4:junit4] 2> 733727 T1783 C1591 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10060 (-1438859482703593472)]} 0 0
[junit4:junit4] 2> 733735 T1769 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 733741 T1803 C1590 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[60 (-1438859482718273536)]} 0 1
[junit4:junit4] 2> 733741 T1805 C1590 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10060 (-1438859482718273537)]} 0 1
[junit4:junit4] 2> 733755 T1787 C1591 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[66 (1438859482729807872)]} 0 3
[junit4:junit4] 2> 733763 T1786 C1591 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10066 (1438859482736099328)]} 0 6
[junit4:junit4] 2> 733765 T1802 C1590 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[66 (1438859482742390784)]} 0 1
[junit4:junit4] 2> 733775 T1801 C1590 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10066 (1438859482752876544)]} 0 1
[junit4:junit4] 2> 733785 T1782 C1591 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[61 (-1438859482764410880)]} 0 0
[junit4:junit4] 2> 733797 T1784 C1591 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10061 (-1438859482776993792)]} 0 0
[junit4:junit4] 2> 733797 T1806 C1590 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[61 (-1438859482776993792)]} 0 0
[junit4:junit4] 2> 733815 T1804 C1590 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {delete=[10061 (-1438859482795868160)]} 0 0
[junit4:junit4] 2> 733816 T1783 C1591 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[67 (1438859482795868160)]} 0 1
[junit4:junit4] 2> 733817 T1769 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 733820 T1851 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4b9bb066 name:ZooKeeperConnection Watcher:127.0.0.1:49642/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 733823 T1787 C1591 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10067 (1438859482803208192)]} 0 1
[junit4:junit4] 2> 733823 T1803 C1590 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[67 (1438859482803208192)]} 0 1
[junit4:junit4] 2> 733824 T1769 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 733835 T1805 C1590 P49649 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[10067 (1438859482814742528)]} 0 3
[junit4:junit4] 2> 733848 T1769 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 733854 T1785 C1591 P49645 oasup.LogUpdateProcessor.finish [collection1] webapp=/e_ro/m path=/update params={wt=javabin&version=2} {add=[68 (1438859482835714048)]} 0 1
[junit4:junit4] 2> 733875 T1802
[...truncated too long message...]
2> 829383 T1769 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1722172963
[junit4:junit4] 2> 829406 T1861 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:49652_e_ro%2Fm",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:49652/e_ro/m"}
[junit4:junit4] 2> 829415 T1851 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> 829487 T1791 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 829487 T1791 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> 829487 T1791 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 830388 T1769 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 830388 T1769 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 830391 T1769 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@3398866b
[junit4:junit4] 2> 830402 T1769 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=45,cumulative_deletesById=32,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 830403 T1769 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 830403 T1769 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 830404 T1769 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 830411 T1769 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 830412 T1769 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 830412 T1769 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty2/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty2/index;done=false>>]
[junit4:junit4] 2> 830413 T1769 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty2/index
[junit4:junit4] 2> 830413 T1769 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty2 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty2;done=false>>]
[junit4:junit4] 2> 830414 T1769 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.RecoveryZkTest-1372203311977/jetty2
[junit4:junit4] 2> 830415 T1861 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89928716254773258-127.0.0.1:49652_e_ro%2Fm-n_0000000003) am no longer a leader.
[junit4:junit4] 2> 830432 T1769 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/e_ro/m,null}
[junit4:junit4] 2> 830506 T1769 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 830511 T1769 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:49642 49642
[junit4:junit4] 2> 830604 T1811 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 830610 T1811 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[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=10E034D761A8A91B -Dtests.slow=true -Dtests.locale=es_CL -Dtests.timezone=America/Managua -Dtests.file.encoding=UTF-8
[junit4:junit4] FAILURE 119s | RecoveryZkTest.testDistribSearch <<<
[junit4:junit4] > Throwable #1: java.lang.AssertionError: expected:<130> but was:<26>
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([10E034D761A8A91B:9106BACF16F7C927]:0)
[junit4:junit4] > at org.apache.solr.cloud.RecoveryZkTest.doTest(RecoveryZkTest.java:108)
[junit4:junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:724)
[junit4:junit4] 2> 830769 T1769 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 118651 T1768 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4:junit4] 2> 831720 T1851 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 831720 T1851 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> 831721 T1851 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {range_facet_l=MockVariableIntBlock(baseBlockSize=52), text=PostingsFormat(name=SimpleText), _version_=PostingsFormat(name=Memory doPackFST= true), rnd_b=PostingsFormat(name=Direct), intDefault=PostingsFormat(name=Memory doPackFST= true), timestamp=MockVariableIntBlock(baseBlockSize=52), id=PostingsFormat(name=Direct), a_t=MockVariableIntBlock(baseBlockSize=52), range_facet_sl=PostingsFormat(name=Direct), range_facet_si=MockVariableIntBlock(baseBlockSize=52), other_tl1=PostingsFormat(name=Memory doPackFST= true), multiDefault=MockVariableIntBlock(baseBlockSize=52), a_si=PostingsFormat(name=Memory doPackFST= true)}, docValues:{timestamp=DocValuesFormat(name=Disk)}, sim=DefaultSimilarity, locale=es_CL, timezone=America/Managua
[junit4:junit4] 2> NOTE: Mac OS X 10.8.4 x86_64/Oracle Corporation 1.7.0_25 (64-bit)/cpus=2,threads=1,free=34869696,total=170483712
[junit4:junit4] 2> NOTE: All tests run in this JVM: [DocumentBuilderTest, IndexReaderFactoryTest, TestQueryUtils, TestRandomFaceting, TestSchemaNameResource, DistributedQueryElevationComponentTest, TestSolrXMLSerializer, IndexSchemaRuntimeFieldTest, TestQueryTypes, BadCopyFieldTest, SynonymTokenizerTest, TestRangeQuery, TestUniqueKeyFieldResource, DisMaxRequestHandlerTest, StatelessScriptUpdateProcessorFactoryTest, SolrIndexConfigTest, DOMUtilTest, TestCloudManagedSchemaAddField, TestRTGBase, TestMultiCoreConfBootstrap, JSONWriterTest, SpellCheckComponentTest, TestSerializedLuceneMatchVersion, TestSolrDeletionPolicy2, ReturnFieldsTest, TestCodecSupport, TestBinaryField, LeaderElectionTest, TestClassNameShortening, TestBadConfig, DefaultValueUpdateProcessorTest, PeerSyncTest, CacheHeaderTest, TestMergePolicyConfig, SchemaVersionSpecificBehaviorTest, TestJmxIntegration, TestDynamicFieldCollectionResource, TestSchemaSimilarityResource, TestDistributedSearch, TestSuggestSpellingConverter, TestFastLRUCache, TestLuceneMatchVersion, DirectSolrConnectionTest, TestAtomicUpdateErrorCases, TestAnalyzedSuggestions, TestQuerySenderListener, TestTrie, NumericFieldsTest, ClusterStateTest, TestCopyFieldCollectionResource, TestValueSourceCache, SuggesterFSTTest, SolrPluginUtilsTest, ShardRoutingTest, SpatialFilterTest, SpellPossibilityIteratorTest, FileBasedSpellCheckerTest, TestDefaultSimilarityFactory, TestDocSet, TestRealTimeGet, MoreLikeThisHandlerTest, TestReload, WordBreakSolrSpellCheckerTest, TestFieldTypeCollectionResource, ZkNodePropsTest, UpdateParamsTest, TestExtendedDismaxParser, TestWordDelimiterFilterFactory, DistributedTermsComponentTest, DirectUpdateHandlerOptimizeTest, BasicDistributedZk2Test, OverseerCollectionProcessorTest, SearchHandlerTest, TermVectorComponentTest, SliceStateUpdateTest, SOLR749Test, RecoveryZkTest]
[junit4:junit4] Completed in 119.72s, 1 test, 1 failure <<< FAILURES!
[...truncated 681 lines...]
BUILD FAILED
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:386: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:366: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/build.xml:39: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/build.xml:181: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/solr/common-build.xml:437: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:1243: The following error occurred while executing this line:
/Users/jenkins/jenkins-slave/workspace/Lucene-Solr-trunk-MacOSX/lucene/common-build.xml:887: There were test failures: 297 suites, 1253 tests, 1 failure, 18 ignored (6 assumptions)
Total time: 87 minutes 47 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0 -XX:-UseCompressedOops -XX:+UseSerialGC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure