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/13 23:00:23 UTC
[JENKINS] Lucene-Solr-trunk-Windows (64bit/jdk1.7.0_21) - Build #
2926 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-trunk-Windows/2926/
Java: 64bit/jdk1.7.0_21 -XX:+UseCompressedOops -XX:+UseG1GC
2 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeyShardSplitTest.testDistribSearch
Error Message:
Server at http://127.0.0.1:59040 returned non ok status:500, message:Server Error
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:59040 returned non ok status:500, message:Server Error
at __randomizedtesting.SeedInfo.seed([39DBC7F6ED50EA35:B83D49EE9A0F8A09]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.cloud.ShardSplitTest.splitShard(ShardSplitTest.java:228)
at org.apache.solr.cloud.ChaosMonkeyShardSplitTest.doTest(ChaosMonkeyShardSplitTest.java:136)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
at sun.reflect.GeneratedMethodAccessor42.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:601)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:722)
REGRESSION: org.apache.solr.cloud.RecoveryZkTest.testDistribSearch
Error Message:
expected:<2097> but was:<66>
Stack Trace:
java.lang.AssertionError: expected:<2097> but was:<66>
at __randomizedtesting.SeedInfo.seed([39DBC7F6ED50EA35:B83D49EE9A0F8A09]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.junit.Assert.assertEquals(Assert.java:456)
at org.apache.solr.cloud.RecoveryZkTest.doTest(RecoveryZkTest.java:108)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:601)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:722)
Build Log:
[...truncated 9360 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.RecoveryZkTest
[junit4:junit4] 2> 527650 T1017 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4] 2> 527655 T1017 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\solrtest-RecoveryZkTest-1371154820257
[junit4:junit4] 2> 527658 T1017 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 527659 T1018 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 527770 T1017 oasc.ZkTestServer.run start zk server on port:55739
[junit4:junit4] 2> 527772 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 527794 T1024 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1b713f80 name:ZooKeeperConnection Watcher:127.0.0.1:55739 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 527795 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 527795 T1017 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 527803 T1019 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13f3f322cad0000, likely client has closed socket
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2>
[junit4:junit4] 2> 527805 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 527811 T1026 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@20b376d8 name:ZooKeeperConnection Watcher:127.0.0.1:55739/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 527811 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 527812 T1017 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 527819 T1017 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 527826 T1017 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 527832 T1017 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 527840 T1017 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 527841 T1017 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 527854 T1017 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 527855 T1017 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 527863 T1017 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 527864 T1017 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 527873 T1017 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 527874 T1017 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 527882 T1017 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 527883 T1017 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 527890 T1017 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 527890 T1017 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 527899 T1017 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 527899 T1017 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 527907 T1017 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 527908 T1017 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 527916 T1017 oasc.AbstractZkTestCase.putConfig put C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test-files\solr\collection1\conf\synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 527917 T1017 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 527927 T1019 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13f3f322cad0001, likely client has closed socket
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2>
[junit4:junit4] 2> 528424 T1017 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 528433 T1017 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55746
[junit4:junit4] 2> 528434 T1017 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 528434 T1017 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 528435 T1017 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1371154820527
[junit4:junit4] 2> 528435 T1017 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1371154820527\solr.xml
[junit4:junit4] 2> 528435 T1017 oasc.CoreContainer.<init> New CoreContainer 218255493
[junit4:junit4] 2> 528436 T1017 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1371154820527\'
[junit4:junit4] 2> 528437 T1017 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1371154820527\'
[junit4:junit4] 2> 528569 T1017 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 528569 T1017 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 528570 T1017 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 528571 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 528571 T1017 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 528572 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 528572 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 528572 T1017 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 528572 T1017 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 528573 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 528584 T1017 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 528585 T1017 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55739/solr
[junit4:junit4] 2> 528585 T1017 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 528588 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 528607 T1037 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6e566f04 name:ZooKeeperConnection Watcher:127.0.0.1:55739 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 528607 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 528612 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 528612 T1019 oazs.NIOServerCnxn.doIO WARN caught end of stream exception EndOfStreamException: Unable to read additional data from client sessionid 0x13f3f322cad0002, likely client has closed socket
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:220)
[junit4:junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4:junit4] 2> at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2>
[junit4:junit4] 2> 528620 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 528625 T1039 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6bf7754f name:ZooKeeperConnection Watcher:127.0.0.1:55739/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 528626 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 528630 T1017 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 528639 T1017 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 528646 T1017 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 528653 T1017 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55746_
[junit4:junit4] 2> 528657 T1017 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55746_
[junit4:junit4] 2> 528667 T1017 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 528684 T1017 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 528692 T1017 oasc.Overseer.start Overseer (id=89860002301149187-127.0.0.1:55746_-n_0000000000) starting
[junit4:junit4] 2> 528703 T1017 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 528715 T1041 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 528717 T1017 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 528725 T1017 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 528730 T1017 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 528739 T1040 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 528743 T1042 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 528743 T1042 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 530397 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 530398 T1040 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:55746_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55746"}
[junit4:junit4] 2> 530398 T1040 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 530398 T1040 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 530418 T1039 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> 530947 T1042 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1371154820527\collection1
[junit4:junit4] 2> 530947 T1042 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 530948 T1042 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 530948 T1042 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 530953 T1042 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1371154820527\collection1\'
[junit4:junit4] 2> 530956 T1042 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1371154820527/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 530958 T1042 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-controljetty-1371154820527/collection1/lib/README' to classloader
[junit4:junit4] 2> 531038 T1042 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 531132 T1042 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 531138 T1042 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 531144 T1042 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 531926 T1042 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 531940 T1042 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 531945 T1042 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 531973 T1042 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 531984 T1042 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 531993 T1042 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 531995 T1042 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 531996 T1042 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 531996 T1042 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 531999 T1042 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 531999 T1042 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 531999 T1042 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 532000 T1042 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-controljetty-1371154820527\collection1\, dataDir=.\org.apache.solr.cloud.RecoveryZkTest-1371154820255/control/data\
[junit4:junit4] 2> 532000 T1042 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@43ae7f6b
[junit4:junit4] 2> 532000 T1042 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 532001 T1042 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.RecoveryZkTest-1371154820255/control/data\
[junit4:junit4] 2> 532001 T1042 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.RecoveryZkTest-1371154820255/control/data\index/
[junit4:junit4] 2> 532001 T1042 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.RecoveryZkTest-1371154820255\control\data\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 532001 T1042 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.RecoveryZkTest-1371154820255/control/data\index
[junit4:junit4] 2> 532009 T1042 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2a261eb1 lockFactory=org.apache.lucene.store.NativeFSLockFactory@474f0278),segFN=segments_1,generation=1}
[junit4:junit4] 2> 532009 T1042 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 532014 T1042 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 532014 T1042 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 532015 T1042 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 532016 T1042 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 532016 T1042 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 532016 T1042 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 532016 T1042 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 532017 T1042 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 532017 T1042 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 532030 T1042 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 532038 T1042 oass.SolrIndexSearcher.<init> Opening Searcher@4441c76e main
[junit4:junit4] 2> 532039 T1042 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.RecoveryZkTest-1371154820255\control\data\tlog
[junit4:junit4] 2> 532041 T1042 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 532041 T1042 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 532047 T1043 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4441c76e main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 532048 T1042 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 532048 T1042 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:55746 collection:control_collection shard:shard1
[junit4:junit4] 2> 532051 T1042 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 532075 T1042 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 532086 T1042 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 532086 T1042 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 532087 T1042 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:55746/collection1/
[junit4:junit4] 2> 532087 T1042 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 532087 T1042 oasc.SyncStrategy.syncToMe http://127.0.0.1:55746/collection1/ has no replicas
[junit4:junit4] 2> 532088 T1042 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:55746/collection1/
[junit4:junit4] 2> 532088 T1042 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 533735 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 533762 T1039 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> 533785 T1042 oasc.ZkController.register We are http://127.0.0.1:55746/collection1/ and leader is http://127.0.0.1:55746/collection1/
[junit4:junit4] 2> 533785 T1042 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:55746
[junit4:junit4] 2> 533785 T1042 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 533785 T1042 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 533785 T1042 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 533792 T1042 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 533794 T1017 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 533794 T1017 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 533794 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 533806 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 533809 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 533813 T1046 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@64714418 name:ZooKeeperConnection Watcher:127.0.0.1:55739/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 533814 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 533817 T1017 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 533822 T1017 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 534330 T1017 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 534335 T1017 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55758
[junit4:junit4] 2> 534338 T1017 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 534338 T1017 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 534339 T1017 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1371154826422
[junit4:junit4] 2> 534339 T1017 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1371154826422\solr.xml
[junit4:junit4] 2> 534340 T1017 oasc.CoreContainer.<init> New CoreContainer 513920798
[junit4:junit4] 2> 534341 T1017 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1371154826422\'
[junit4:junit4] 2> 534341 T1017 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1371154826422\'
[junit4:junit4] 2> 534521 T1017 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 534522 T1017 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 534523 T1017 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 534523 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 534523 T1017 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 534524 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 534524 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 534524 T1017 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 534527 T1017 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 534528 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 534543 T1017 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 534544 T1017 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55739/solr
[junit4:junit4] 2> 534544 T1017 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 534547 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 534567 T1057 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6deea3bf name:ZooKeeperConnection Watcher:127.0.0.1:55739 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 534569 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 534577 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 534586 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 534590 T1059 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@427d6429 name:ZooKeeperConnection Watcher:127.0.0.1:55739/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 534591 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 534602 T1017 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 535427 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 535428 T1040 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:55746_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55746"}
[junit4:junit4] 2> 535440 T1046 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> 535440 T1039 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> 535441 T1059 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> 535711 T1017 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55758_
[junit4:junit4] 2> 535718 T1017 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55758_
[junit4:junit4] 2> 535732 T1046 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 535732 T1046 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> 535734 T1039 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 535735 T1039 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> 535735 T1059 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 535736 T1059 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> 535769 T1060 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 535771 T1060 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 537101 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 537104 T1040 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:55758_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55758"}
[junit4:junit4] 2> 537104 T1040 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 1
[junit4:junit4] 2> 537104 T1040 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 537121 T1046 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> 537122 T1039 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> 537123 T1059 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> 537977 T1060 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1371154826422\collection1
[junit4:junit4] 2> 537977 T1060 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 537979 T1060 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 537979 T1060 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 537982 T1060 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1371154826422\collection1\'
[junit4:junit4] 2> 537984 T1060 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1371154826422/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 537986 T1060 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty1-1371154826422/collection1/lib/README' to classloader
[junit4:junit4] 2> 538052 T1060 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 538129 T1060 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 538132 T1060 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 538139 T1060 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 538906 T1060 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 538920 T1060 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 538923 T1060 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 538950 T1060 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 538955 T1060 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 538962 T1060 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 538966 T1060 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 538966 T1060 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 538966 T1060 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 538968 T1060 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 538968 T1060 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 538969 T1060 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 538969 T1060 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty1-1371154826422\collection1\, dataDir=.\org.apache.solr.cloud.RecoveryZkTest-1371154820255/jetty1\
[junit4:junit4] 2> 538969 T1060 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@43ae7f6b
[junit4:junit4] 2> 538969 T1060 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 538971 T1060 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.RecoveryZkTest-1371154820255/jetty1\
[junit4:junit4] 2> 538971 T1060 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.RecoveryZkTest-1371154820255/jetty1\index/
[junit4:junit4] 2> 538971 T1060 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.RecoveryZkTest-1371154820255\jetty1\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 538971 T1060 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.RecoveryZkTest-1371154820255/jetty1\index
[junit4:junit4] 2> 538976 T1060 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@70ec67e1 lockFactory=org.apache.lucene.store.NativeFSLockFactory@559921c),segFN=segments_1,generation=1}
[junit4:junit4] 2> 538976 T1060 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 538981 T1060 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 538981 T1060 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 538982 T1060 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 538983 T1060 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 538983 T1060 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 538983 T1060 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 538983 T1060 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 538984 T1060 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 538984 T1060 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 538997 T1060 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 539005 T1060 oass.SolrIndexSearcher.<init> Opening Searcher@258b8c46 main
[junit4:junit4] 2> 539005 T1060 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.RecoveryZkTest-1371154820255\jetty1\tlog
[junit4:junit4] 2> 539008 T1060 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 539008 T1060 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 539015 T1061 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@258b8c46 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 539016 T1060 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 539016 T1060 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:55758 collection:collection1 shard:shard1
[junit4:junit4] 2> 539019 T1060 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 539041 T1060 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 539047 T1060 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 539047 T1060 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 539047 T1060 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:55758/collection1/
[junit4:junit4] 2> 539047 T1060 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 539047 T1060 oasc.SyncStrategy.syncToMe http://127.0.0.1:55758/collection1/ has no replicas
[junit4:junit4] 2> 539047 T1060 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:55758/collection1/
[junit4:junit4] 2> 539048 T1060 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 540235 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 540255 T1046 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> 540256 T1059 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> 540255 T1039 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> 540271 T1060 oasc.ZkController.register We are http://127.0.0.1:55758/collection1/ and leader is http://127.0.0.1:55758/collection1/
[junit4:junit4] 2> 540271 T1060 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:55758
[junit4:junit4] 2> 540271 T1060 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 540271 T1060 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 540272 T1060 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 540276 T1060 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 540278 T1017 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 540279 T1017 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 540279 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 540764 T1017 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 540770 T1017 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:55767
[junit4:junit4] 2> 540771 T1017 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 540772 T1017 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 540772 T1017 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1371154832888
[junit4:junit4] 2> 540772 T1017 oasc.CoreContainer$Initializer.initialize looking for solr config file: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1371154832888\solr.xml
[junit4:junit4] 2> 540773 T1017 oasc.CoreContainer.<init> New CoreContainer 448585040
[junit4:junit4] 2> 540773 T1017 oasc.CoreContainer.load Loading CoreContainer using Solr Home: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1371154832888\'
[junit4:junit4] 2> 540774 T1017 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1371154832888\'
[junit4:junit4] 2> 540888 T1017 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 540888 T1017 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 540889 T1017 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 540889 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 540890 T1017 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 540890 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 540890 T1017 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 540891 T1017 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 540891 T1017 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 540892 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 540901 T1017 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 540903 T1017 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:55739/solr
[junit4:junit4] 2> 540903 T1017 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 540905 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 540923 T1073 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a3b78c4 name:ZooKeeperConnection Watcher:127.0.0.1:55739 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 540924 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 540928 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 540935 T1017 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 540942 T1075 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3a9d2953 name:ZooKeeperConnection Watcher:127.0.0.1:55739/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 540943 T1017 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 540953 T1017 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 541755 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 541756 T1040 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:55758_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55758"}
[junit4:junit4] 2> 541771 T1046 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> 541771 T1059 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> 541771 T1075 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> 541771 T1039 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> 541949 T1017 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55767_
[junit4:junit4] 2> 541953 T1017 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55767_
[junit4:junit4] 2> 541958 T1075 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> 541960 T1046 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 541960 T1059 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 541960 T1059 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> 541960 T1039 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 541961 T1039 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> 541960 T1046 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> 541966 T1075 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 541978 T1076 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 541979 T1076 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 543266 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 543270 T1040 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:55767_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55767"}
[junit4:junit4] 2> 543271 T1040 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4] 2> 543271 T1040 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 543288 T1046 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> 543290 T1039 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> 543290 T1075 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> 543291 T1059 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> 543962 T1076 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1371154832888\collection1
[junit4:junit4] 2> 543963 T1076 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 543963 T1076 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 543964 T1076 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 543968 T1076 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: 'C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1371154832888\collection1\'
[junit4:junit4] 2> 543970 T1076 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1371154832888/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 543972 T1076 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/C:/Users/JenkinsSlave/workspace/Lucene-Solr-trunk-Windows/solr/build/solr-core/test/J0/org.apache.solr.cloud.RecoveryZkTest-jetty2-1371154832888/collection1/lib/README' to classloader
[junit4:junit4] 2> 544049 T1076 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 544139 T1076 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 544143 T1076 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 544152 T1076 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 544872 T1076 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 544884 T1076 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 544889 T1076 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 544920 T1076 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 544926 T1076 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 544932 T1076 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 544936 T1076 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 544937 T1076 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 544937 T1076 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 544939 T1076 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 544939 T1076 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARN Expected key, got STRING
[junit4:junit4] 2> 544941 T1076 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 544941 T1076 oasc.SolrCore.<init> [collection1] Opening new SolrCore at C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0\.\org.apache.solr.cloud.RecoveryZkTest-jetty2-1371154832888\collection1\, dataDir=.\org.apache.solr.cloud.RecoveryZkTest-1371154820255/jetty2\
[junit4:junit4] 2> 544941 T1076 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@43ae7f6b
[junit4:junit4] 2> 544941 T1076 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 544942 T1076 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.RecoveryZkTest-1371154820255/jetty2\
[junit4:junit4] 2> 544942 T1076 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=.\org.apache.solr.cloud.RecoveryZkTest-1371154820255/jetty2\index/
[junit4:junit4] 2> 544943 T1076 oasc.SolrCore.initIndex WARN [collection1] Solr index directory '.\org.apache.solr.cloud.RecoveryZkTest-1371154820255\jetty2\index' doesn't exist. Creating new index...
[junit4:junit4] 2> 544943 T1076 oasc.CachingDirectoryFactory.get return new directory for .\org.apache.solr.cloud.RecoveryZkTest-1371154820255/jetty2\index
[junit4:junit4] 2> 544948 T1076 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@81681a6 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6df5ea0b),segFN=segments_1,generation=1}
[junit4:junit4] 2> 544949 T1076 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 544953 T1076 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 544953 T1076 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 544953 T1076 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 544954 T1076 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 544954 T1076 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 544954 T1076 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 544954 T1076 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 544956 T1076 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 544956 T1076 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 544967 T1076 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 544976 T1076 oass.SolrIndexSearcher.<init> Opening Searcher@2cf9462c main
[junit4:junit4] 2> 544976 T1076 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=.\org.apache.solr.cloud.RecoveryZkTest-1371154820255\jetty2\tlog
[junit4:junit4] 2> 544978 T1076 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 544978 T1076 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 544983 T1077 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2cf9462c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 544984 T1076 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 544984 T1076 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:55767 collection:collection1 shard:shard1
[junit4:junit4] 2> 544995 T1076 oasc.ZkController.register We are http://127.0.0.1:55767/collection1/ and leader is http://127.0.0.1:55758/collection1/
[junit4:junit4] 2> 544995 T1076 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:55767
[junit4:junit4] 2> 544996 T1076 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 544996 T1076 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C205 name=collection1 org.apache.solr.core.SolrCore@2b6e340a url=http://127.0.0.1:55767/collection1 node=127.0.0.1:55767_ C205_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:55767_, base_url=http://127.0.0.1:55767}
[junit4:junit4] 2> 544997 T1078 C205 P55767 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 544998 T1078 C205 P55767 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 544998 T1078 C205 P55767 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 544998 T1078 C205 P55767 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 544999 T1076 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 545002 T1078 C205 P55767 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 545003 T1017 oass.SolrDispatchFilter.init user.dir=C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build\solr-core\test\J0
[junit4:junit4] 2> 545005 T1017 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 545005 T1017 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 545014 T1055 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 3, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 545014 T1017 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> ASYNC NEW_CORE C206 name=collection1 org.apache.solr.core.SolrCore@7d8fd3f7 url=http://127.0.0.1:55746/collection1 node=127.0.0.1:55746_ C206_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:55746_, base_url=http://127.0.0.1:55746, leader=true}
[junit4:junit4] 2> 545037 T1031 C206 P55746 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2a261eb1 lockFactory=org.apache.lucene.store.NativeFSLockFactory@474f0278),segFN=segments_1,generation=1}
[junit4:junit4] 2> 545038 T1031 C206 P55746 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 545042 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[1 (1437760055025860608)]} 0 9
[junit4:junit4] 2> 545042 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10001 (1437760055024812032)]} 0 11
[junit4:junit4] 2> ASYNC NEW_CORE C207 name=collection1 org.apache.solr.core.SolrCore@59729bd9 url=http://127.0.0.1:55758/collection1 node=127.0.0.1:55758_ C207_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:55758_, base_url=http://127.0.0.1:55758, leader=true}
[junit4:junit4] 2> 545066 T1051 C207 P55758 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@70ec67e1 lockFactory=org.apache.lucene.store.NativeFSLockFactory@559921c),segFN=segments_1,generation=1}
[junit4:junit4] 2> 545067 T1051 C207 P55758 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 545070 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[1 (1437760055054172160)]} 0 10
[junit4:junit4] 2> 545070 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10001 (1437760055062560768)]} 0 3
[junit4:junit4] 2> 545174 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10002 (1437760055169515520)]} 0 4
[junit4:junit4] 2> 545174 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[2 (1437760055172661248)]} 0 4
[junit4:junit4] 2> 545178 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10002 (1437760055177904129)]} 0 1
[junit4:junit4] 2> 545179 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[2 (1437760055177904128)]} 0 1
[junit4:junit4] 2> 545211 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10003 (1437760055212507136)]} 0 1
[junit4:junit4] 2> 545215 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[3 (1437760055216701440)]} 0 1
[junit4:junit4] 2> 545218 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10003 (1437760055219847168)]} 0 1
[junit4:junit4] 2> 545220 T1017 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 55767
[junit4:junit4] 2> 545220 T1017 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=448585040
[junit4:junit4] 2> 545221 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[3 (1437760055221944320)]} 0 1
[junit4:junit4] 2> 545269 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10004 (1437760055272275968)]} 0 2
[junit4:junit4] 2> 545269 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[4 (1437760055272275969)]} 0 1
[junit4:junit4] 2> 545274 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10004 (1437760055277518849)]} 0 1
[junit4:junit4] 2> 545275 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[4 (1437760055277518848)]} 0 2
[junit4:junit4] 2> 545371 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10003 (-1437760055379230720)]} 0 1
[junit4:junit4] 2> 545373 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[3 (-1437760055380279296)]} 0 3
[junit4:junit4] 2> 545376 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10003 (-1437760055385522176)]} 0 1
[junit4:junit4] 2> 545377 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[3 (-1437760055385522177)]} 0 1
[junit4:junit4] 2> 545381 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10005 (1437760055389716480)]} 0 1
[junit4:junit4] 2> 545381 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[5 (1437760055389716481)]} 0 1
[junit4:junit4] 2> 545386 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10005 (1437760055394959360)]} 0 2
[junit4:junit4] 2> 545386 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[5 (1437760055394959361)]} 0 1
[junit4:junit4] 2> 545476 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10006 (1437760055489331201)]} 0 1
[junit4:junit4] 2> 545477 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[6 (1437760055489331200)]} 0 2
[junit4:junit4] 2> 545480 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[6 (1437760055493525504)]} 0 1
[junit4:junit4] 2> 545480 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10006 (1437760055493525505)]} 0 1
[junit4:junit4] 2> 545528 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[7 (1437760055543857152)]} 0 1
[junit4:junit4] 2> 545529 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10007 (1437760055543857153)]} 0 2
[junit4:junit4] 2> 545532 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[7 (1437760055548051456)]} 0 1
[junit4:junit4] 2> 545534 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10007 (1437760055550148608)]} 0 1
[junit4:junit4] 2> 545560 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[5 (-1437760055578460160)]} 0 0
[junit4:junit4] 2> 545561 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10005 (-1437760055579508736)]} 0 0
[junit4:junit4] 2> 545563 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[5 (-1437760055581605888)]} 0 0
[junit4:junit4] 2> 545566 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10005 (-1437760055584751616)]} 0 0
[junit4:junit4] 2> 545569 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[8 (1437760055586848768)]} 0 1
[junit4:junit4] 2> 545572 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10008 (1437760055591043072)]} 0 0
[junit4:junit4] 2> 545576 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[8 (1437760055594188800)]} 0 1
[junit4:junit4] 2> 545577 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10008 (1437760055596285952)]} 0 0
[junit4:junit4] 2> 545662 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[6 (-1437760055685414912)]} 0 2
[junit4:junit4] 2> 545663 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10006 (-1437760055686463488)]} 0 0
[junit4:junit4] 2> 545666 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[6 (-1437760055688560640)]} 0 1
[junit4:junit4] 2> 545667 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10006 (-1437760055689609216)]} 0 1
[junit4:junit4] 2> 545670 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[9 (1437760055692754944)]} 0 1
[junit4:junit4] 2> 545671 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10009 (1437760055693803520)]} 0 1
[junit4:junit4] 2> 545674 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[9 (1437760055696949248)]} 0 1
[junit4:junit4] 2> 545675 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10009 (1437760055697997824)]} 0 1
[junit4:junit4] 2> 545697 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10 (1437760055721066496)]} 0 1
[junit4:junit4] 2> 545697 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10010 (1437760055721066497)]} 0 1
[junit4:junit4] 2> 545701 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10 (1437760055726309376)]} 0 1
[junit4:junit4] 2> 545703 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10010 (1437760055727357952)]} 0 1
[junit4:junit4] 2> 545766 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[11 (1437760055794466816)]} 0 1
[junit4:junit4] 2> 545770 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10011 (1437760055797612544)]} 0 1
[junit4:junit4] 2> 545770 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[11 (1437760055797612544)]} 0 1
[junit4:junit4] 2> 545774 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10011 (1437760055801806848)]} 0 1
[junit4:junit4] 2> 545809 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[12 (1437760055838507008)]} 0 1
[junit4:junit4] 2> 545811 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10012 (1437760055841652736)]} 0 1
[junit4:junit4] 2> 545814 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[12 (1437760055844798464)]} 0 1
[junit4:junit4] 2> 545815 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10012 (1437760055844798465)]} 0 1
[junit4:junit4] 2> 545851 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[12 (-1437760055883595776)]} 0 1
[junit4:junit4] 2> 545851 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10012 (-1437760055883595777)]} 0 0
[junit4:junit4] 2> 545855 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10012 (-1437760055886741505)]} 0 1
[junit4:junit4] 2> 545855 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[12 (-1437760055886741504)]} 0 1
[junit4:junit4] 2> 545858 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10013 (1437760055889887232)]} 0 1
[junit4:junit4] 2> 545858 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[13 (1437760055889887233)]} 0 1
[junit4:junit4] 2> 545862 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10013 (1437760055895130112)]} 0 1
[junit4:junit4] 2> 545863 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[13 (1437760055895130113)]} 0 1
[junit4:junit4] 2> 545880 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10014 (1437760055912955904)]} 0 1
[junit4:junit4] 2> 545880 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[14 (1437760055912955905)]} 0 1
[junit4:junit4] 2> 545885 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10014 (1437760055917150208)]} 0 2
[junit4:junit4] 2> 545885 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[14 (1437760055917150209)]} 0 2
[junit4:junit4] 2> 545927 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10015 (1437760055962238977)]} 0 2
[junit4:junit4] 2> 545927 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[15 (1437760055962238976)]} 0 2
[junit4:junit4] 2> 545932 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[15 (1437760055966433280)]} 0 2
[junit4:junit4] 2> 545933 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10015 (1437760055966433281)]} 0 3
[junit4:junit4] 2> 545940 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[16 (1437760055975870464)]} 0 2
[junit4:junit4] 2> 545940 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10016 (1437760055975870465)]} 0 1
[junit4:junit4] 2> 545944 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[16 (1437760055980064768)]} 0 1
[junit4:junit4] 2> 545945 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10016 (1437760055980064769)]} 0 2
[junit4:junit4] 2> 546032 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[15 (-1437760056073388032)]} 0 1
[junit4:junit4] 2> 546033 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10015 (-1437760056074436608)]} 0 1
[junit4:junit4] 2> 546036 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[15 (-1437760056077582336)]} 0 0
[junit4:junit4] 2> 546038 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10015 (-1437760056078630912)]} 0 1
[junit4:junit4] 2> 546040 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[17 (1437760056080728064)]} 0 1
[junit4:junit4] 2> 546042 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10017 (1437760056083873792)]} 0 2
[junit4:junit4] 2> 546045 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[17 (1437760056087019520)]} 0 1
[junit4:junit4] 2> 546046 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10017 (1437760056088068096)]} 0 1
[junit4:junit4] 2> 546139 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[18 (1437760056184537088)]} 0 1
[junit4:junit4] 2> 546142 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10018 (1437760056185585664)]} 0 4
[junit4:junit4] 2> 546146 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[18 (1437760056191877120)]} 0 2
[junit4:junit4] 2> 546148 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10018 (1437760056193974272)]} 0 1
[junit4:junit4] 2> 546198 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[19 (1437760056246403072)]} 0 2
[junit4:junit4] 2> 546199 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10019 (1437760056248500224)]} 0 1
[junit4:junit4] 2> 546203 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[19 (1437760056252694528)]} 0 1
[junit4:junit4] 2> 546205 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10019 (1437760056253743104)]} 0 1
[junit4:junit4] 2> 546212 T1017 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 546212 T1017 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 546214 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10016 (-1437760056264228864)]} 0 0
[junit4:junit4] 2> 546218 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[16 (-1437760056267374592)]} 0 1
[junit4:junit4] 2> 546221 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10016 (-1437760056271568896)]} 0 0
[junit4:junit4] 2> 546225 T1017 oasc.RecoveryStrategy.close WARN Stopping recovery for zkNodeName=3core=collection1
[junit4:junit4] 2> 546228 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[16 (-1437760056278908928)]} 0 0
[junit4:junit4] 2> 546231 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10020 (1437760056282054656)]} 0 1
[junit4:junit4] 2> 546234 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[20 (1437760056285200384)]} 0 0
[junit4:junit4] 2> 546236 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10020 (1437760056286248960)]} 0 1
[junit4:junit4] 2> 546242 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[20 (1437760056292540416)]} 0 1
[junit4:junit4] 2> 546274 T1040 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 546275 T1040 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:55767_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55767"}
[junit4:junit4] 2> 546284 T1040 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:55767_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55767"}
[junit4:junit4] 2> 546293 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10021 (1437760056347066368)]} 0 0
[junit4:junit4] 2> 546296 T1039 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> 546297 T1075 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> 546297 T1059 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> 546296 T1046 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> 546300 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10021 (1437760056353357824)]} 0 3
[junit4:junit4] 2> 546305 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[21 (1437760056357552128)]} 0 2
[junit4:junit4] 2> 546312 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[21 (1437760056364892160)]} 0 2
[junit4:junit4] 2> 546375 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10018 (-1437760056433049600)]} 0 0
[junit4:junit4] 2> 546379 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10018 (-1437760056437243904)]} 0 1
[junit4:junit4] 2> 546383 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10022 (1437760056440389632)]} 0 1
[junit4:junit4] 2> 546387 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[18 (-1437760056444583936)]} 0 1
[junit4:junit4] 2> 546387 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10022 (1437760056444583936)]} 0 1
[junit4:junit4] 2> 546391 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[18 (-1437760056449826816)]} 0 0
[junit4:junit4] 2> 546395 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[22 (1437760056452972544)]} 0 1
[junit4:junit4] 2> 546400 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[22 (1437760056459264000)]} 0 1
[junit4:junit4] 2> 546428 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10020 (-1437760056488624128)]} 0 0
[junit4:junit4] 2> 546432 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10020 (-1437760056492818432)]} 0 1
[junit4:junit4] 2> 546436 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10023 (1437760056495964160)]} 0 1
[junit4:junit4] 2> 546439 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10023 (1437760056500158464)]} 0 1
[junit4:junit4] 2> 546439 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[20 (-1437760056500158464)]} 0 0
[junit4:junit4] 2> 546443 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[20 (-1437760056504352768)]} 0 0
[junit4:junit4] 2> 546448 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[23 (1437760056508547072)]} 0 1
[junit4:junit4] 2> 546452 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[23 (1437760056513789952)]} 0 1
[junit4:junit4] 2> 546464 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10024 (1437760056526372864)]} 0 0
[junit4:junit4] 2> 546469 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10024 (1437760056530567168)]} 0 1
[junit4:junit4] 2> 546478 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[24 (1437760056541052928)]} 0 0
[junit4:junit4] 2> 546482 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[24 (1437760056545247232)]} 0 1
[junit4:junit4] 2> 546533 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10022 (-1437760056598724608)]} 0 0
[junit4:junit4] 2> 546537 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10022 (-1437760056602918912)]} 0 1
[junit4:junit4] 2> 546542 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10025 (1437760056607113216)]} 0 1
[junit4:junit4] 2> 546546 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[22 (-1437760056612356096)]} 0 0
[junit4:junit4] 2> 546546 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10025 (1437760056612356096)]} 0 0
[junit4:junit4] 2> 546550 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[22 (-1437760056615501824)]} 0 1
[junit4:junit4] 2> 546555 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[25 (1437760056620744704)]} 0 1
[junit4:junit4] 2> 546558 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[25 (1437760056624939008)]} 0 1
[junit4:junit4] 2> 546595 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10026 (1437760056662687744)]} 0 1
[junit4:junit4] 2> 546599 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10026 (1437760056667930624)]} 0 1
[junit4:junit4] 2> 546608 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[26 (1437760056677367808)]} 0 1
[junit4:junit4] 2> 546613 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[26 (1437760056682610688)]} 0 0
[junit4:junit4] 2> 546634 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10023 (-1437760056704630784)]} 0 0
[junit4:junit4] 2> 546642 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10023 (-1437760056713019392)]} 0 0
[junit4:junit4] 2> 546646 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[23 (-1437760056717213697)]} 0 0
[junit4:junit4] 2> 546646 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10027 (1437760056717213696)]} 0 0
[junit4:junit4] 2> 546651 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[23 (-1437760056722456576)]} 0 1
[junit4:junit4] 2> 546651 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10027 (1437760056721408000)]} 0 1
[junit4:junit4] 2> 546657 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[27 (1437760056727699456)]} 0 3
[junit4:junit4] 2> 546662 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[27 (1437760056732942336)]} 0 1
[junit4:junit4] 2> 546699 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10025 (-1437760056772788224)]} 0 1
[junit4:junit4] 2> 546702 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10025 (-1437760056775933952)]} 0 1
[junit4:junit4] 2> 546707 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10028 (1437760056781176832)]} 0 2
[junit4:junit4] 2> 546712 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[25 (-1437760056786419712)]} 0 1
[junit4:junit4] 2> 546712 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10028 (1437760056786419712)]} 0 1
[junit4:junit4] 2> 546716 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[25 (-1437760056790614016)]} 0 0
[junit4:junit4] 2> 546721 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[28 (1437760056794808320)]} 0 2
[junit4:junit4] 2> 546727 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[28 (1437760056801099776)]} 0 2
[junit4:junit4] 2> 546804 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10026 (-1437760056882888704)]} 0 0
[junit4:junit4] 2> 546808 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10026 (-1437760056887083008)]} 0 1
[junit4:junit4] 2> 546812 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10029 (1437760056891277312)]} 0 1
[junit4:junit4] 2> 546816 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10029 (1437760056895471616)]} 0 1
[junit4:junit4] 2> 546820 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[26 (-1437760056898617344)]} 0 1
[junit4:junit4] 2> 546822 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[26 (-1437760056901763072)]} 0 0
[junit4:junit4] 2> 546826 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[29 (1437760056905957376)]} 0 1
[junit4:junit4] 2> 546832 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[29 (1437760056912248832)]} 0 1
[junit4:junit4] 2> 546886 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10030 (1437760056967823360)]} 0 1
[junit4:junit4] 2> 546891 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10030 (1437760056973066240)]} 0 1
[junit4:junit4] 2> 546902 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[30 (1437760056985649152)]} 0 1
[junit4:junit4] 2> 546905 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[30 (1437760056988794880)]} 0 1
[junit4:junit4] 2> 546948 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10031 (1437760057032835072)]} 0 1
[junit4:junit4] 2> 546952 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10031 (1437760057038077952)]} 0 1
[junit4:junit4] 2> 546963 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[31 (1437760057048563712)]} 0 1
[junit4:junit4] 2> 546967 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[31 (1437760057052758016)]} 0 1
[junit4:junit4] 2> 546979 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10028 (-1437760057066389504)]} 0 1
[junit4:junit4] 2> 546983 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10028 (-1437760057070583808)]} 0 1
[junit4:junit4] 2> 546988 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10032 (1437760057074778112)]} 0 2
[junit4:junit4] 2> 546992 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10032 (1437760057078972416)]} 0 1
[junit4:junit4] 2> 546993 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[28 (-1437760057081069568)]} 0 0
[junit4:junit4] 2> 546997 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[28 (-1437760057085263872)]} 0 0
[junit4:junit4] 2> 547000 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[32 (1437760057088409600)]} 0 0
[junit4:junit4] 2> 547007 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[32 (1437760057093652480)]} 0 2
[junit4:junit4] 2> 547085 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10029 (-1437760057177538560)]} 0 0
[junit4:junit4] 2> 547089 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10029 (-1437760057181732864)]} 0 1
[junit4:junit4] 2> 547093 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10033 (1437760057185927168)]} 0 1
[junit4:junit4] 2> 547097 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10033 (1437760057190121472)]} 0 1
[junit4:junit4] 2> 547101 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[29 (-1437760057194315776)]} 0 0
[junit4:junit4] 2> 547107 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[29 (-1437760057200607232)]} 0 0
[junit4:junit4] 2> 547110 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[33 (1437760057202704384)]} 0 1
[junit4:junit4] 2> 547115 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[33 (1437760057207947264)]} 0 1
[junit4:junit4] 2> 547196 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10034 (1437760057292881920)]} 0 1
[junit4:junit4] 2> 547200 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10034 (1437760057298124800)]} 0 1
[junit4:junit4] 2> 547214 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[34 (1437760057312804864)]} 0 1
[junit4:junit4] 2> 547219 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[34 (1437760057316999168)]} 0 1
[junit4:junit4] 2> 547244 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10035 (1437760057344262144)]} 0 1
[junit4:junit4] 2> 547250 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10035 (1437760057349505024)]} 0 2
[junit4:junit4] 2> 547263 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[35 (1437760057364185088)]} 0 1
[junit4:junit4] 2> 547264 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10036 (1437760057364185089)]} 0 1
[junit4:junit4] 2> 547268 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[35 (1437760057369427969)]} 0 1
[junit4:junit4] 2> 547268 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10036 (1437760057369427968)]} 0 1
[junit4:junit4] 2> 547284 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[36 (1437760057385156608)]} 0 1
[junit4:junit4] 2> 547289 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[36 (1437760057390399488)]} 0 0
[junit4:junit4] 2> 547302 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10037 (1437760057404030976)]} 0 1
[junit4:junit4] 2> 547306 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10037 (1437760057409273856)]} 0 1
[junit4:junit4] 2> 547322 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[37 (1437760057425002496)]} 0 2
[junit4:junit4] 2> 547327 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[37 (1437760057431293952)]} 0 1
[junit4:junit4] 2> 547400 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10038 (1437760057507840000)]} 0 0
[junit4:junit4] 2> 547405 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10038 (1437760057512034304)]} 0 2
[junit4:junit4] 2> 547423 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[38 (1437760057531957248)]} 0 1
[junit4:junit4] 2> 547428 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[38 (1437760057537200128)]} 0 1
[junit4:junit4] 2> 547447 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10039 (1437760057557123072)]} 0 1
[junit4:junit4] 2> 547453 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10039 (1437760057562365952)]} 0 2
[junit4:junit4] 2> 547469 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[39 (1437760057580191744)]} 0 1
[junit4:junit4] 2> 547475 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[39 (1437760057585434624)]} 0 1
[junit4:junit4] 2> 547492 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10033 (-1437760057604308992)]} 0 1
[junit4:junit4] 2> 547496 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10033 (-1437760057608503296)]} 0 1
[junit4:junit4] 2> 547499 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10040 (1437760057610600448)]} 0 1
[junit4:junit4] 2> 547504 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10040 (1437760057615843328)]} 0 1
[junit4:junit4] 2> 547516 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[33 (-1437760057629474816)]} 0 2
[junit4:junit4] 2> 547519 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[33 (-1437760057632620544)]} 0 1
[junit4:junit4] 2> 547521 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10041 (1437760057633669120)]} 0 1
[junit4:junit4] 2> 547524 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[40 (1437760057636814848)]} 0 1
[junit4:junit4] 2> 547527 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10041 (1437760057639960576)]} 0 1
[junit4:junit4] 2> 547528 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[40 (1437760057641009152)]} 0 1
[junit4:junit4] 2> 547546 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[41 (1437760057660932096)]} 0 1
[junit4:junit4] 2> 547551 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[41 (1437760057665126400)]} 0 1
[junit4:junit4] 2> 547571 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10042 (1437760057686097920)]} 0 1
[junit4:junit4] 2> 547576 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10042 (1437760057691340800)]} 0 1
[junit4:junit4] 2> 547585 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10034 (-1437760057701826560)]} 0 0
[junit4:junit4] 2> 547590 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10034 (-1437760057707069440)]} 0 0
[junit4:junit4] 2> 547596 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10043 (1437760057712312320)]} 0 2
[junit4:junit4] 2> 547596 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[42 (1437760057712312321)]} 0 2
[junit4:junit4] 2> 547601 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10043 (1437760057717555200)]} 0 2
[junit4:junit4] 2> 547602 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[42 (1437760057719652352)]} 0 0
[junit4:junit4] 2> 547611 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[34 (-1437760057729089536)]} 0 1
[junit4:junit4] 2> 547614 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[34 (-1437760057732235264)]} 0 0
[junit4:junit4] 2> 547619 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[43 (1437760057736429568)]} 0 1
[junit4:junit4] 2> 547623 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[43 (1437760057740623872)]} 0 1
[junit4:junit4] 2> 547639 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10040 (-1437760057758449664)]} 0 1
[junit4:junit4] 2> 547643 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10040 (-1437760057762643968)]} 0 0
[junit4:junit4] 2> 547648 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10044 (1437760057766838272)]} 0 1
[junit4:junit4] 2> 547653 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10044 (1437760057772081152)]} 0 1
[junit4:junit4] 2> 547657 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[40 (-1437760057777324032)]} 0 1
[junit4:junit4] 2> 547661 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[40 (-1437760057781518336)]} 0 1
[junit4:junit4] 2> 547665 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[44 (1437760057783615488)]} 0 2
[junit4:junit4] 2> 547670 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[44 (1437760057789906944)]} 0 1
[junit4:junit4] 2> 547733 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10045 (1437760057855967232)]} 0 1
[junit4:junit4] 2> 547738 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10045 (1437760057861210112)]} 0 1
[junit4:junit4] 2> 547749 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[45 (1437760057873793024)]} 0 0
[junit4:junit4] 2> 547753 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[45 (1437760057876938752)]} 0 1
[junit4:junit4] 2> 547778 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10043 (-1437760057904201728)]} 0 0
[junit4:junit4] 2> 547782 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10043 (-1437760057908396032)]} 0 1
[junit4:junit4] 2> 547788 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10046 (1437760057912590336)]} 0 2
[junit4:junit4] 2> 547792 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10046 (1437760057918881792)]} 0 1
[junit4:junit4] 2> 547797 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[43 (-1437760057924124672)]} 0 1
[junit4:junit4] 2> 547801 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[43 (-1437760057928318976)]} 0 1
[junit4:junit4] 2> 547807 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[46 (1437760057934610432)]} 0 1
[junit4:junit4] 2> 547812 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[46 (1437760057938804736)]} 0 1
[junit4:junit4] 2> 547841 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10044 (-1437760057970262016)]} 0 1
[junit4:junit4] 2> 547845 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10044 (-1437760057974456320)]} 0 0
[junit4:junit4] 2> 547849 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10047 (1437760057978650624)]} 0 1
[junit4:junit4] 2> 547853 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10047 (1437760057982844928)]} 0 1
[junit4:junit4] 2> 547863 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[44 (-1437760057992282112)]} 0 1
[junit4:junit4] 2> 547865 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[44 (-1437760057995427840)]} 0 0
[junit4:junit4] 2> 547870 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[47 (1437760058000670720)]} 0 0
[junit4:junit4] 2> 547875 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[47 (1437760058005913600)]} 0 1
[junit4:junit4] 2> 547878 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10048 (1437760058008010752)]} 0 1
[junit4:junit4] 2> 547883 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10048 (1437760058013253632)]} 0 1
[junit4:junit4] 2> 547900 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[48 (1437760058032128000)]} 0 1
[junit4:junit4] 2> 547905 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[48 (1437760058037370880)]} 0 1
[junit4:junit4] 2> 547935 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10045 (-1437760058068828160)]} 0 0
[junit4:junit4] 2> 547938 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10045 (-1437760058071973888)]} 0 0
[junit4:junit4] 2> 547943 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10049 (1437760058076168192)]} 0 1
[junit4:junit4] 2> 547947 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10049 (1437760058081411072)]} 0 1
[junit4:junit4] 2> 547958 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[45 (-1437760058092945408)]} 0 1
[junit4:junit4] 2> 547962 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[45 (-1437760058097139712)]} 0 1
[junit4:junit4] 2> 547967 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[49 (1437760058101334016)]} 0 2
[junit4:junit4] 2> 547971 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[49 (1437760058106576896)]} 0 1
[junit4:junit4] 2> 548044 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10047 (-1437760058183122944)]} 0 0
[junit4:junit4] 2> 548049 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10047 (-1437760058188365824)]} 0 0
[junit4:junit4] 2> 548053 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10050 (1437760058191511552)]} 0 1
[junit4:junit4] 2> 548057 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10050 (1437760058195705856)]} 0 1
[junit4:junit4] 2> 548069 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[47 (-1437760058209337344)]} 0 1
[junit4:junit4] 2> 548073 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[47 (-1437760058213531648)]} 0 0
[junit4:junit4] 2> 548077 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[50 (1437760058216677376)]} 0 1
[junit4:junit4] 2> 548082 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[50 (1437760058221920256)]} 0 2
[junit4:junit4] 2> 548129 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10048 (-1437760058272251904)]} 0 0
[junit4:junit4] 2> 548134 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10048 (-1437760058277494784)]} 0 1
[junit4:junit4] 2> 548139 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10051 (1437760058281689088)]} 0 1
[junit4:junit4] 2> 548143 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10051 (1437760058286931968)]} 0 1
[junit4:junit4] 2> 548155 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[48 (-1437760058299514880)]} 0 1
[junit4:junit4] 2> 548157 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[48 (-1437760058301612032)]} 0 0
[junit4:junit4] 2> 548163 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[51 (1437760058305806336)]} 0 2
[junit4:junit4] 2> 548167 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[51 (1437760058312097792)]} 0 1
[junit4:junit4] 2> 548181 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10049 (-1437760058326777856)]} 0 1
[junit4:junit4] 2> 548185 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10049 (-1437760058330972160)]} 0 0
[junit4:junit4] 2> 548191 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10052 (1437760058336215040)]} 0 1
[junit4:junit4] 2> 548195 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10052 (1437760058341457920)]} 0 1
[junit4:junit4] 2> 548205 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[49 (-1437760058351943680)]} 0 0
[junit4:junit4] 2> 548208 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[49 (-1437760058355089408)]} 0 0
[junit4:junit4] 2> 548214 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[52 (1437760058360332288)]} 0 1
[junit4:junit4] 2> 548219 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[52 (1437760058365575168)]} 0 1
[junit4:junit4] 2> 548228 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10051 (-1437760058376060928)]} 0 0
[junit4:junit4] 2> 548232 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10051 (-1437760058380255232)]} 0 1
[junit4:junit4] 2> 548237 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10053 (1437760058384449536)]} 0 2
[junit4:junit4] 2> 548244 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10053 (1437760058391789568)]} 0 1
[junit4:junit4] 2> 548253 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[51 (-1437760058402275328)]} 0 0
[junit4:junit4] 2> 548258 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[51 (-1437760058407518208)]} 0 1
[junit4:junit4] 2> 548261 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10054 (1437760058409615360)]} 0 1
[junit4:junit4] 2> 548262 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[53 (1437760058410663936)]} 0 1
[junit4:junit4] 2> 548266 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10054 (1437760058414858240)]} 0 2
[junit4:junit4] 2> 548266 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[53 (1437760058414858241)]} 0 1
[junit4:junit4] 2> 548281 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[54 (1437760058431635456)]} 0 1
[junit4:junit4] 2> 548286 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[54 (1437760058436878336)]} 0 1
[junit4:junit4] 2> 548293 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10055 (1437760058443169792)]} 0 1
[junit4:junit4] 2> 548297 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10055 (1437760058447364096)]} 0 1
[junit4:junit4] 2> 548315 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[55 (1437760058466238464)]} 0 2
[junit4:junit4] 2> 548319 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[55 (1437760058469384192)]} 0 2
[junit4:junit4] 2> 548337 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10054 (-1437760058490355712)]} 0 0
[junit4:junit4] 2> 548340 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10054 (-1437760058493501440)]} 0 1
[junit4:junit4] 2> 548344 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10056 (1437760058497695744)]} 0 1
[junit4:junit4] 2> 548347 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10056 (1437760058500841472)]} 0 1
[junit4:junit4] 2> 548351 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10057 (1437760058505035776)]} 0 1
[junit4:junit4] 2> 548356 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10057 (1437760058510278656)]} 0 1
[junit4:junit4] 2> 548361 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[54 (-1437760058514472960)]} 0 2
[junit4:junit4] 2> 548365 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[54 (-1437760058519715840)]} 0 0
[junit4:junit4] 2> 548370 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[56 (1437760058523910144)]} 0 2
[junit4:junit4] 2> 548373 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[56 (1437760058528104448)]} 0 0
[junit4:junit4] 2> 548378 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[57 (1437760058532298752)]} 0 1
[junit4:junit4] 2> 548382 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[57 (1437760058537541632)]} 0 1
[junit4:junit4] 2> 548391 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10058 (1437760058546978816)]} 0 0
[junit4:junit4] 2> 548396 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10058 (1437760058551173120)]} 0 1
[junit4:junit4] 2> 548418 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[58 (1437760058575290368)]} 0 0
[junit4:junit4] 2> 548423 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[58 (1437760058578436096)]} 0 2
[junit4:junit4] 2> 548478 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10057 (-1437760058638204928)]} 0 0
[junit4:junit4] 2> 548482 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10057 (-1437760058642399232)]} 0 0
[junit4:junit4] 2> 548487 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10059 (1437760058646593536)]} 0 1
[junit4:junit4] 2> 548491 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10059 (1437760058651836416)]} 0 1
[junit4:junit4] 2> 548505 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[57 (-1437760058666516480)]} 0 1
[junit4:junit4] 2> 548508 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[57 (-1437760058669662208)]} 0 1
[junit4:junit4] 2> 548511 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[59 (1437760058672807936)]} 0 0
[junit4:junit4] 2> 548516 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[59 (1437760058677002240)]} 0 1
[junit4:junit4] 2> 548565 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10060 (1437760058729431040)]} 0 0
[junit4:junit4] 2> 548571 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10060 (1437760058734673920)]} 0 1
[junit4:junit4] 2> 548595 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[60 (1437760058759839744)]} 0 2
[junit4:junit4] 2> 548598 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[60 (1437760058762985472)]} 0 1
[junit4:junit4] 2> 548619 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10061 (1437760058786054144)]} 0 1
[junit4:junit4] 2> 548623 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10061 (1437760058790248448)]} 0 0
[junit4:junit4] 2> 548645 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[61 (1437760058813317120)]} 0 0
[junit4:junit4] 2> 548650 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[61 (1437760058818560000)]} 0 1
[junit4:junit4] 2> 548672 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10061 (-1437760058841628672)]} 0 0
[junit4:junit4] 2> 548676 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10061 (-1437760058845822976)]} 0 0
[junit4:junit4] 2> 548681 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10062 (1437760058850017280)]} 0 1
[junit4:junit4] 2> 548686 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10062 (1437760058855260160)]} 0 2
[junit4:junit4] 2> 548699 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[61 (-1437760058869940224)]} 0 0
[junit4:junit4] 2> 548702 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[61 (-1437760058873085952)]} 0 1
[junit4:junit4] 2> 548706 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[62 (1437760058876231680)]} 0 1
[junit4:junit4] 2> 548710 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[62 (1437760058880425984)]} 0 1
[junit4:junit4] 2> 548731 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10063 (1437760058902446080)]} 0 1
[junit4:junit4] 2> 548735 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10063 (1437760058906640384)]} 0 2
[junit4:junit4] 2> 548755 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[63 (1437760058928660480)]} 0 1
[junit4:junit4] 2> 548759 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[63 (1437760058932854784)]} 0 1
[junit4:junit4] 2> 548778 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10064 (1437760058951729152)]} 0 2
[junit4:junit4] 2> 548781 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10064 (1437760058954874880)]} 0 1
[junit4:junit4] 2> 548803 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[64 (1437760058976894976)]} 0 3
[junit4:junit4] 2> 548806 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[64 (1437760058982137856)]} 0 0
[junit4:junit4] 2> 548824 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10064 (-1437760059001012224)]} 0 1
[junit4:junit4] 2> 548827 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10064 (-1437760059003109376)]} 0 1
[junit4:junit4] 2> 548831 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10065 (1437760059008352256)]} 0 1
[junit4:junit4] 2> 548835 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10065 (1437760059012546560)]} 0 1
[junit4:junit4] 2> 548849 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[64 (-1437760059027226624)]} 0 1
[junit4:junit4] 2> 548853 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[64 (-1437760059030372352)]} 0 1
[junit4:junit4] 2> 548857 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[65 (1437760059035615232)]} 0 1
[junit4:junit4] 2> 548860 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[65 (1437760059038760960)]} 0 0
[junit4:junit4] 2> 548869 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10066 (1437760059047149568)]} 0 1
[junit4:junit4] 2> 548873 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10066 (1437760059052392448)]} 0 1
[junit4:junit4] 2> 548884 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10067 (1437760059062878208)]} 0 1
[junit4:junit4] 2> 548888 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10067 (1437760059067072512)]} 0 1
[junit4:junit4] 2> 548894 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[66 (1437760059074412544)]} 0 1
[junit4:junit4] 2> 548899 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[66 (1437760059078606848)]} 0 1
[junit4:junit4] 2> 548910 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[67 (1437760059090141184)]} 0 2
[junit4:junit4] 2> 548913 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[67 (1437760059094335488)]} 0 0
[junit4:junit4] 2> 548957 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10068 (1437760059139424256)]} 0 1
[junit4:junit4] 2> 548961 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10068 (1437760059143618560)]} 0 1
[junit4:junit4] 2> 548982 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[68 (1437760059166687232)]} 0 1
[junit4:junit4] 2> 548987 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[68 (1437760059171930112)]} 0 0
[junit4:junit4] 2> 549017 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10067 (-1437760059203387392)]} 0 1
[junit4:junit4] 2> 549020 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10067 (-1437760059206533120)]} 0 0
[junit4:junit4] 2> 549025 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10069 (1437760059210727424)]} 0 1
[junit4:junit4] 2> 549028 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10069 (1437760059214921728)]} 0 1
[junit4:junit4] 2> 549043 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[67 (-1437760059230650368)]} 0 0
[junit4:junit4] 2> 549047 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[67 (-1437760059234844672)]} 0 1
[junit4:junit4] 2> 549050 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[69 (1437760059237990400)]} 0 1
[junit4:junit4] 2> 549054 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[69 (1437760059242184704)]} 0 1
[junit4:junit4] 2> 549066 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10070 (1437760059254767616)]} 0 1
[junit4:junit4] 2> 549071 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10070 (1437760059258961920)]} 0 2
[junit4:junit4] 2> 549091 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[70 (1437760059280982016)]} 0 1
[junit4:junit4] 2> 549095 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[70 (1437760059284127744)]} 0 1
[junit4:junit4] 2> 549099 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10071 (1437760059288322048)]} 0 1
[junit4:junit4] 2> 549103 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10071 (1437760059293564928)]} 0 1
[junit4:junit4] 2> 549123 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[71 (1437760059314536448)]} 0 1
[junit4:junit4] 2> 549127 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[71 (1437760059318730752)]} 0 1
[junit4:junit4] 2> 549177 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10072 (1437760059370110976)]} 0 1
[junit4:junit4] 2> 549181 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10072 (1437760059375353856)]} 0 1
[junit4:junit4] 2> 549201 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[72 (1437760059394228224)]} 0 2
[junit4:junit4] 2> 549204 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[72 (1437760059398422528)]} 0 1
[junit4:junit4] 2> 549265 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10073 (1437760059463434240)]} 0 1
[junit4:junit4] 2> 549270 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10073 (1437760059467628544)]} 0 1
[junit4:junit4] 2> 549288 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[73 (1437760059487551488)]} 0 0
[junit4:junit4] 2> 549293 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[73 (1437760059491745792)]} 0 1
[junit4:junit4] 2> 549294 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10074 (1437760059493842944)]} 0 0
[junit4:junit4] 2> 549298 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10074 (1437760059496988672)]} 0 1
[junit4:junit4] 2> 549317 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[74 (1437760059516911616)]} 0 2
[junit4:junit4] 2> 549321 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[74 (1437760059522154496)]} 0 1
[junit4:junit4] 2> 549378 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10075 (1437760059580874752)]} 0 2
[junit4:junit4] 2> 549382 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10075 (1437760059586117632)]} 0 1
[junit4:junit4] 2> 549402 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[75 (1437760059607089152)]} 0 0
[junit4:junit4] 2> 549406 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[75 (1437760059611283456)]} 0 1
[junit4:junit4] 2> 549446 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10076 (1437760059653226496)]} 0 1
[junit4:junit4] 2> 549451 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10076 (1437760059656372224)]} 0 2
[junit4:junit4] 2> 549469 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[76 (1437760059677343744)]} 0 0
[junit4:junit4] 2> 549474 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[76 (1437760059681538048)]} 0 1
[junit4:junit4] 2> 549541 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10077 (1437760059751792640)]} 0 2
[junit4:junit4] 2> 549544 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10077 (1437760059754938368)]} 0 1
[junit4:junit4] 2> 549563 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[77 (1437760059775909888)]} 0 1
[junit4:junit4] 2> 549567 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[77 (1437760059780104192)]} 0 1
[junit4:junit4] 2> 549577 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10068 (-1437760059790589952)]} 0 0
[junit4:junit4] 2> 549581 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10068 (-1437760059794784256)]} 0 0
[junit4:junit4] 2> 549587 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10078 (1437760059798978560)]} 0 2
[junit4:junit4] 2> 549591 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10078 (1437760059804221440)]} 0 1
[junit4:junit4] 2> 549603 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[68 (-1437760059817852928)]} 0 1
[junit4:junit4] 2> 549606 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[68 (-1437760059820998656)]} 0 0
[junit4:junit4] 2> 549610 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[78 (1437760059825192960)]} 0 0
[junit4:junit4] 2> 549616 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[78 (1437760059830435840)]} 0 1
[junit4:junit4] 2> 549675 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10070 (-1437760059893350400)]} 0 0
[junit4:junit4] 2> 549679 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10070 (-1437760059897544704)]} 0 1
[junit4:junit4] 2> 549683 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10079 (1437760059901739008)]} 0 1
[junit4:junit4] 2> 549687 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10079 (1437760059904884736)]} 0 2
[junit4:junit4] 2> 549698 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[70 (-1437760059917467648)]} 0 1
[junit4:junit4] 2> 549701 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[70 (-1437760059920613376)]} 0 0
[junit4:junit4] 2> 549705 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[79 (1437760059924807680)]} 0 1
[junit4:junit4] 2> 549709 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[79 (1437760059929001984)]} 0 0
[junit4:junit4] 2> 549769 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10072 (-1437760059991916544)]} 0 1
[junit4:junit4] 2> 549772 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10072 (-1437760059994013696)]} 0 1
[junit4:junit4] 2> 549775 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10080 (1437760059997159424)]} 0 1
[junit4:junit4] 2> 549778 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10080 (1437760060000305152)]} 0 1
[junit4:junit4] 2> 549791 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[72 (-1437760060014985216)]} 0 0
[junit4:junit4] 2> 549794 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[72 (-1437760060018130944)]} 0 0
[junit4:junit4] 2> 549798 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[80 (1437760060022325248)]} 0 0
[junit4:junit4] 2> 549802 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[80 (1437760060025470976)]} 0 1
[junit4:junit4] 2> 549820 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10081 (1437760060045393920)]} 0 1
[junit4:junit4] 2> 549824 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10081 (1437760060049588224)]} 0 1
[junit4:junit4] 2> 549841 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10082 (1437760060066365440)]} 0 1
[junit4:junit4] 2> 549849 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[81 (1437760060074754048)]} 0 2
[junit4:junit4] 2> 549849 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10082 (1437760060074754048)]} 0 1
[junit4:junit4] 2> 549857 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[81 (1437760060083142656)]} 0 1
[junit4:junit4] 2> 549861 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10083 (1437760060088385536)]} 0 1
[junit4:junit4] 2> 549866 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10083 (1437760060092579840)]} 0 1
[junit4:junit4] 2> 549874 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[82 (1437760060100968448)]} 0 1
[junit4:junit4] 2> 549878 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[82 (1437760060106211328)]} 0 0
[junit4:junit4] 2> 549889 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[83 (1437760060117745664)]} 0 0
[junit4:junit4] 2> 549894 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[83 (1437760060121939968)]} 0 1
[junit4:junit4] 2> 549936 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10073 (-1437760060167028736)]} 0 1
[junit4:junit4] 2> 549939 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10073 (-1437760060170174464)]} 0 1
[junit4:junit4] 2> 549943 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10084 (1437760060174368768)]} 0 1
[junit4:junit4] 2> 549946 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10084 (1437760060177514496)]} 0 1
[junit4:junit4] 2> 549972 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[73 (-1437760060204777472)]} 0 1
[junit4:junit4] 2> 549975 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[73 (-1437760060207923200)]} 0 0
[junit4:junit4] 2> 549978 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[84 (1437760060211068928)]} 0 0
[junit4:junit4] 2> 549983 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[84 (1437760060215263232)]} 0 1
[junit4:junit4] 2> 550037 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10074 (-1437760060272934912)]} 0 0
[junit4:junit4] 2> 550040 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10074 (-1437760060276080640)]} 0 1
[junit4:junit4] 2> 550045 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10085 (1437760060280274944)]} 0 1
[junit4:junit4] 2> 550049 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10085 (1437760060284469248)]} 0 1
[junit4:junit4] 2> 550073 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[74 (-1437760060310683648)]} 0 1
[junit4:junit4] 2> 550076 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[74 (-1437760060313829376)]} 0 0
[junit4:junit4] 2> 550080 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[85 (1437760060318023680)]} 0 1
[junit4:junit4] 2> 550084 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[85 (1437760060322217984)]} 0 1
[junit4:junit4] 2> 550092 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10078 (-1437760060330606592)]} 0 0
[junit4:junit4] 2> 550095 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10078 (-1437760060333752320)]} 0 1
[junit4:junit4] 2> 550099 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10086 (1437760060337946624)]} 0 1
[junit4:junit4] 2> 550102 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10086 (1437760060341092352)]} 0 0
[junit4:junit4] 2> 550127 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[78 (-1437760060367306752)]} 0 1
[junit4:junit4] 2> 550130 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[78 (-1437760060370452480)]} 0 0
[junit4:junit4] 2> 550134 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[86 (1437760060374646784)]} 0 0
[junit4:junit4] 2> 550139 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[86 (1437760060378841088)]} 0 2
[junit4:junit4] 2> 550186 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10079 (-1437760060429172736)]} 0 1
[junit4:junit4] 2> 550188 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10079 (-1437760060431269888)]} 0 0
[junit4:junit4] 2> 550192 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10087 (1437760060435464192)]} 0 1
[junit4:junit4] 2> 550195 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10087 (1437760060438609920)]} 0 1
[junit4:junit4] 2> 550222 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[79 (-1437760060466921472)]} 0 1
[junit4:junit4] 2> 550226 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[79 (-1437760060470067200)]} 0 1
[junit4:junit4] 2> 550230 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[87 (1437760060475310080)]} 0 1
[junit4:junit4] 2> 550233 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[87 (1437760060478455808)]} 0 0
[junit4:junit4] 2> 550276 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10080 (-1437760060523544576)]} 0 0
[junit4:junit4] 2> 550280 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10080 (-1437760060526690304)]} 0 1
[junit4:junit4] 2> 550284 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10088 (1437760060531933184)]} 0 1
[junit4:junit4] 2> 550287 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10088 (1437760060535078912)]} 0 1
[junit4:junit4] 2> 550315 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[80 (-1437760060563390464)]} 0 1
[junit4:junit4] 2> 550319 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[80 (-1437760060568633344)]} 0 1
[junit4:junit4] 2> 550322 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[88 (1437760060571779072)]} 0 1
[junit4:junit4] 2> 550327 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[88 (1437760060575973376)]} 0 1
[junit4:junit4] 2> 550353 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10081 (-1437760060604284928)]} 0 0
[junit4:junit4] 2> 550358 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10081 (-1437760060609527808)]} 0 1
[junit4:junit4] 2> 550362 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10089 (1437760060612673536)]} 0 1
[junit4:junit4] 2> 550367 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10089 (1437760060617916416)]} 0 1
[junit4:junit4] 2> 550392 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[81 (-1437760060645179392)]} 0 0
[junit4:junit4] 2> 550395 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[81 (-1437760060648325120)]} 0 0
[junit4:junit4] 2> 550400 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[89 (1437760060652519424)]} 0 1
[junit4:junit4] 2> 550404 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[89 (1437760060657762304)]} 0 1
[junit4:junit4] 2> 550450 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10082 (-1437760060705996800)]} 0 1
[junit4:junit4] 2> 550454 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10082 (-1437760060710191104)]} 0 1
[junit4:junit4] 2> 550457 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10090 (1437760060713336832)]} 0 1
[junit4:junit4] 2> 550461 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10090 (1437760060717531136)]} 0 1
[junit4:junit4] 2> 550481 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10091 (1437760060738502656)]} 0 1
[junit4:junit4] 2> 550485 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10091 (1437760060742696960)]} 0 1
[junit4:junit4] 2> 550489 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[82 (-1437760060745842688)]} 0 1
[junit4:junit4] 2> 550493 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[82 (-1437760060751085568)]} 0 1
[junit4:junit4] 2> 550496 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[90 (1437760060754231296)]} 0 1
[junit4:junit4] 2> 550500 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[90 (1437760060758425600)]} 0 1
[junit4:junit4] 2> 550521 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10092 (1437760060778348545)]} 0 2
[junit4:junit4] 2> 550521 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[91 (1437760060778348544)]} 0 2
[junit4:junit4] 2> 550524 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10092 (1437760060782542848)]} 0 1
[junit4:junit4] 2> 550525 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[91 (1437760060784640000)]} 0 1
[junit4:junit4] 2> 550560 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[92 (1437760060821340160)]} 0 1
[junit4:junit4] 2> 550565 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[92 (1437760060826583040)]} 0 1
[junit4:junit4] 2> 550598 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10093 (1437760060860137472)]} 0 2
[junit4:junit4] 2> 550602 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10093 (1437760060864331776)]} 0 1
[junit4:junit4] 2> 550639 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[93 (1437760060904177664)]} 0 1
[junit4:junit4] 2> 550643 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[93 (1437760060908371968)]} 0 1
[junit4:junit4] 2> 550662 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10094 (1437760060928294912)]} 0 0
[junit4:junit4] 2> 550666 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10094 (1437760060932489216)]} 0 1
[junit4:junit4] 2> 550702 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[94 (1437760060970237952)]} 0 1
[junit4:junit4] 2> 550706 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[94 (1437760060974432256)]} 0 1
[junit4:junit4] 2> 550753 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10084 (-1437760061023715328)]} 0 0
[junit4:junit4] 2> 550756 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10084 (-1437760061026861056)]} 0 1
[junit4:junit4] 2> 550761 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10095 (1437760061031055360)]} 0 2
[junit4:junit4] 2> 550766 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10095 (1437760061036298240)]} 0 2
[junit4:junit4] 2> 550789 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10096 (1437760061061464064)]} 0 0
[junit4:junit4] 2> 550793 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10096 (1437760061065658368)]} 0 1
[junit4:junit4] 2> 550793 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[84 (-1437760061065658368)]} 0 0
[junit4:junit4] 2> 550796 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[84 (-1437760061068804096)]} 0 0
[junit4:junit4] 2> 550800 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[95 (1437760061072998400)]} 0 1
[junit4:junit4] 2> 550805 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[95 (1437760061077192704)]} 0 1
[junit4:junit4] 2> 550822 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10097 (1437760061095018496)]} 0 2
[junit4:junit4] 2> 550826 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10097 (1437760061099212800)]} 0 2
[junit4:junit4] 2> 550829 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[96 (1437760061101309952)]} 0 2
[junit4:junit4] 2> 550832 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[96 (1437760061106552832)]} 0 1
[junit4:junit4] 2> 550852 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10098 (1437760061127524352)]} 0 1
[junit4:junit4] 2> 550856 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10098 (1437760061131718656)]} 0 0
[junit4:junit4] 2> 550860 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[97 (1437760061135912960)]} 0 0
[junit4:junit4] 2> 550865 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[97 (1437760061140107264)]} 0 2
[junit4:junit4] 2> 550892 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[98 (1437760061169467392)]} 0 1
[junit4:junit4] 2> 550896 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[98 (1437760061173661696)]} 0 0
[junit4:junit4] 2> 550930 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10087 (-1437760061209313280)]} 0 0
[junit4:junit4] 2> 550934 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10087 (-1437760061213507584)]} 0 0
[junit4:junit4] 2> 550937 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10099 (1437760061216653312)]} 0 1
[junit4:junit4] 2> 550942 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10099 (1437760061220847616)]} 0 1
[junit4:junit4] 2> 550970 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[87 (-1437760061251256320)]} 0 0
[junit4:junit4] 2> 550975 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[87 (-1437760061256499200)]} 0 0
[junit4:junit4] 2> 550979 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[99 (1437760061260693504)]} 0 1
[junit4:junit4] 2> 550984 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[99 (1437760061264887808)]} 0 1
[junit4:junit4] 2> 551030 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10089 (-1437760061314170880)]} 0 0
[junit4:junit4] 2> 551035 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10089 (-1437760061318365184)]} 0 1
[junit4:junit4] 2> 551038 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10100 (1437760061321510912)]} 0 1
[junit4:junit4] 2> 551043 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10100 (1437760061326753792)]} 0 1
[junit4:junit4] 2> 551057 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10101 (1437760061342482432)]} 0 0
[junit4:junit4] 2> 551063 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10101 (1437760061348773888)]} 0 1
[junit4:junit4] 2> 551073 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[89 (-1437760061358211072)]} 0 2
[junit4:junit4] 2> 551077 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[89 (-1437760061363453952)]} 0 1
[junit4:junit4] 2> 551080 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[100 (1437760061366599680)]} 0 1
[junit4:junit4] 2> 551083 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10090 (-1437760061369745408)]} 0 1
[junit4:junit4] 2> 551085 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[100 (1437760061370793984)]} 0 1
[junit4:junit4] 2> 551086 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10090 (-1437760061371842560)]} 0 1
[junit4:junit4] 2> 551091 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10102 (1437760061377085440)]} 0 1
[junit4:junit4] 2> 551095 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10102 (1437760061382328320)]} 0 0
[junit4:junit4] 2> 551099 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[101 (1437760061385474048)]} 0 1
[junit4:junit4] 2> 551102 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[101 (1437760061389668352)]} 0 0
[junit4:junit4] 2> 551122 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[90 (-1437760061410639872)]} 0 1
[junit4:junit4] 2> 551125 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[90 (-1437760061412737024)]} 0 1
[junit4:junit4] 2> 551130 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[102 (1437760061417979904)]} 0 1
[junit4:junit4] 2> 551133 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[102 (1437760061422174208)]} 0 1
[junit4:junit4] 2> 551182 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10092 (-1437760061473554432)]} 0 1
[junit4:junit4] 2> 551185 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10092 (-1437760061476700160)]} 0 1
[junit4:junit4] 2> 551189 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10103 (1437760061480894464)]} 0 1
[junit4:junit4] 2> 551193 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10103 (1437760061485088768)]} 0 1
[junit4:junit4] 2> 551220 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[92 (-1437760061513400320)]} 0 0
[junit4:junit4] 2> 551224 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[92 (-1437760061517594624)]} 0 0
[junit4:junit4] 2> 551229 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[103 (1437760061522837504)]} 0 1
[junit4:junit4] 2> 551233 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[103 (1437760061527031808)]} 0 1
[junit4:junit4] 2> 551238 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10093 (-1437760061532274688)]} 0 0
[junit4:junit4] 2> 551243 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10093 (-1437760061537517568)]} 0 0
[junit4:junit4] 2> 551247 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10104 (1437760061540663296)]} 0 1
[junit4:junit4] 2> 551251 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10104 (1437760061545906176)]} 0 1
[junit4:junit4] 2> 551278 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[93 (-1437760061574217728)]} 0 0
[junit4:junit4] 2> 551282 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10094 (-1437760061578412032)]} 0 1
[junit4:junit4] 2> 551282 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[93 (-1437760061578412032)]} 0 0
[junit4:junit4] 2> 551284 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[10094 (-1437760061580509184)]} 0 0
[junit4:junit4] 2> 551286 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[104 (1437760061581557760)]} 0 1
[junit4:junit4] 2> 551288 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10105 (1437760061582606336)]} 0 2
[junit4:junit4] 2> 551291 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[104 (1437760061587849216)]} 0 0
[junit4:junit4] 2> 551293 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10105 (1437760061589946368)]} 0 1
[junit4:junit4] 2> 551320 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[94 (-1437760061618257920)]} 0 1
[junit4:junit4] 2> 551323 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {delete=[94 (-1437760061621403648)]} 0 0
[junit4:junit4] 2> 551328 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[105 (1437760061625597952)]} 0 1
[junit4:junit4] 2> 551331 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[105 (1437760061629792256)]} 0 0
[junit4:junit4] 2> 551332 T1032 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10106 (1437760061629792256)]} 0 1
[junit4:junit4] 2> 551336 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10106 (1437760061635035136)]} 0 1
[junit4:junit4] 2> 551364 T1033 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10107 (1437760061663346688)]} 0 1
[junit4:junit4] 2> 551368 T1052 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10107 (1437760061667540992)]} 0 1
[junit4:junit4] 2> 551373 T1035 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[106 (1437760061672783872)]} 0 1
[junit4:junit4] 2> 551377 T1054 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[106 (1437760061676978176)]} 0 1
[junit4:junit4] 2> 551382 T1031 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10108 (1437760061682221056)]} 0 1
[junit4:junit4] 2> 551386 T1053 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10108 (1437760061686415360)]} 0 1
[junit4:junit4] 2> 551405 T1034 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[107 (1437760061707386880)]} 0 0
[junit4:junit4] 2> 551410 T1051 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[107 (1437760061712629760)]} 0 1
[junit4:junit4] 2> 551424 T1030 C206 P55746 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[108 (1437760061726261248)]} 0 1
[junit4:junit4] 2> 551428 T1050 C207 P55758 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[108 (1437760061731504128)]} 0 1
[junit4:junit4] 2> 551463 T1032 C206 P55746 oasup.LogUpdatePr
[...truncated too long message...]
ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 2894976 T7605 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> 2894977 T7605 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 2894981 T7514 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 59028
[junit4:junit4] 2> 2895014 T7514 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 2895015 T7514 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:59021 59021
[junit4:junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeyShardSplitTest -Dtests.method=testDistribSearch -Dtests.seed=39DBC7F6ED50EA35 -Dtests.slow=true -Dtests.locale=sr_RS -Dtests.timezone=Europe/Bratislava -Dtests.file.encoding=UTF-8
[junit4:junit4] ERROR 69.4s | ChaosMonkeyShardSplitTest.testDistribSearch <<<
[junit4:junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:59040 returned non ok status:500, message:Server Error
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([39DBC7F6ED50EA35:B83D49EE9A0F8A09]:0)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4:junit4] > at org.apache.solr.cloud.ShardSplitTest.splitShard(ShardSplitTest.java:228)
[junit4:junit4] > at org.apache.solr.cloud.ChaosMonkeyShardSplitTest.doTest(ChaosMonkeyShardSplitTest.java:136)
[junit4:junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2> 2895023 T7514 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> NOTE: test params are: codec=Lucene41, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=sr_RS, timezone=Europe/Bratislava
[junit4:junit4] 2> NOTE: Windows 7 6.1 amd64/Oracle Corporation 1.7.0_21 (64-bit)/cpus=2,threads=2,free=369161992,total=536870912
[junit4:junit4] 2> NOTE: All tests run in this JVM: [SpellCheckComponentTest, TestFastWriter, UnloadDistributedZkTest, CopyFieldTest, DocValuesMultiTest, IndexBasedSpellCheckerTest, CurrencyFieldOpenExchangeTest, TestPropInject, SuggesterTest, TermVectorComponentTest, SolrIndexConfigTest, TestQueryTypes, TestSchemaResource, FullSolrCloudDistribCmdsTest, TestCloudManagedSchema, TestFiltering, SimplePostToolTest, TestTrie, MultiTermTest, SearchHandlerTest, BadCopyFieldTest, LeaderElectionTest, AliasIntegrationTest, DisMaxRequestHandlerTest, TestBinaryField, TestAtomicUpdateErrorCases, TestCoreContainer, TestFieldCollectionResource, TestWriterPerf, TestFieldResource, TestCopyFieldCollectionResource, TestStressVersions, TestSchemaSimilarityResource, TestCoreDiscovery, SolrCoreCheckLockOnStartupTest, BasicZkTest, OutputWriterTest, TestSystemIdResolver, TestBadConfig, PluginInfoTest, TestSolrQueryParserDefaultOperatorResource, CircularListTest, TestFunctionQuery, TestComponentsName, TestFaceting, CachingDirectoryFactoryTest, RecoveryZkTest, IndexReaderFactoryTest, SuggesterFSTTest, TestCollationField, AnalysisAfterCoreReloadTest, TestIBSimilarityFactory, TestWordDelimiterFilterFactory, StandardRequestHandlerTest, BasicDistributedZkTest, BadComponentTest, UpdateParamsTest, TestDefaultSearchFieldResource, IndexSchemaRuntimeFieldTest, SolrInfoMBeanTest, TestSuggestSpellingConverter, TestFieldTypeResource, PreAnalyzedUpdateProcessorTest, TestQuerySenderNoQuery, NotRequiredUniqueKeyTest, ShardSplitTest, TestFastLRUCache, TestAnalyzedSuggestions, BinaryUpdateRequestHandlerTest, TestUniqueKeyFieldResource, QueryElevationComponentTest, TestDynamicFieldCollectionResource, SliceStateTest, SuggesterTSTTest, FieldMutatingUpdateProcessorTest, StatsComponentTest, TestAddFieldRealTimeGet, TestManagedSchemaFieldResource, TestQueryUtils, DirectSolrConnectionTest, TestBinaryResponseWriter, TestReload, TestSweetSpotSimilarityFactory, SampleTest, PingRequestHandlerTest, AutoCommitTest, ShardRoutingTest, TestCodecSupport, TestRandomDVFaceting, SoftAutoCommitTest, TestStressLucene, TestExtendedDismaxParser, CSVRequestHandlerTest, TestSolrXMLSerializer, TestDefaultSimilarityFactory, ZkControllerTest, QueryParsingTest, ExternalFileFieldSortTest, SolrPluginUtilsTest, XsltUpdateRequestHandlerTest, TestDocSet, CacheHeaderTest, DistributedSpellCheckComponentTest, TestSolrQueryParser, DocValuesTest, HighlighterTest, TestPseudoReturnFields, RequiredFieldsTest, TestSolrDeletionPolicy1, NoCacheHeaderTest, TestManagedSchema, TestReversedWildcardFilterFactory, TestNumberUtils, FileBasedSpellCheckerTest, TestSolrJ, TestRecovery, TestRangeQuery, ShowFileRequestHandlerTest, TestPartialUpdateDeduplication, PrimitiveFieldTypeTest, TestMaxScoreQueryParser, TestLuceneMatchVersion, TestUpdate, TestJmxMonitoredMap, TestFoldingMultitermQuery, TestPropInjectDefaults, ClusterStateTest, TestFastOutputStream, TermsComponentTest, BadIndexSchemaTest, TestDynamicFieldResource, TestOmitPositions, DistributedTermsComponentTest, DateFieldTest, TestCSVResponseWriter, OpenExchangeRatesOrgProviderTest, LegacyHTMLStripCharFilterTest, TestSolrXml, TestDocumentBuilder, TestReplicationHandler, TestConfig, RequestHandlersTest, HighlighterConfigTest, TestCloudManagedSchemaAddField, ChaosMonkeySafeLeaderTest, BasicDistributedZk2Test, CollectionsAPIDistributedZkTest, SyncSliceTest, OpenCloseCoreStressTest, OverseerTest, LeaderElectionIntegrationTest, ClusterStateUpdateTest, TestRandomFaceting, ZkSolrClientTest, TestZkChroot, ZkCLITest, ShardRoutingCustomTest, SliceStateUpdateTest, TestDistributedSearch, TestDistributedGrouping, TestHashPartitioner, TermVectorComponentDistributedTest, TestRealTimeGet, TestStressReorder, TestJoin, TestMultiCoreConfBootstrap, HardAutoCommitTest, SimpleFacetsTest, TestSolr4Spatial, SolrCoreTest, TestGroupingSearch, SolrCmdDistributorTest, PeerSyncTest, ConvertedLegacyTest, TestSort, BasicFunctionalityTest, TestLazyCores, DirectUpdateHandlerTest, OverseerCollectionProcessorTest, TestIndexSearcher, DistributedQueryElevationComponentTest, CurrencyFieldXmlFileTest, SolrIndexSplitterTest, SignatureUpdateProcessorFactoryTest, SpellCheckCollatorTest, CoreAdminHandlerTest, SolrRequestParserTest, SpatialFilterTest, SuggesterWFSTTest, TestCSVLoader, PolyFieldTest, WordBreakSolrSpellCheckerTest, SchemaVersionSpecificBehaviorTest, QueryEqualityTest, DirectUpdateHandlerOptimizeTest, DefaultValueUpdateProcessorTest, StatelessScriptUpdateProcessorFactoryTest, SortByFunctionTest, TestRemoteStreaming, DistanceFunctionTest, DebugComponentTest, TestSurroundQueryParser, LukeRequestHandlerTest, DirectSolrSpellCheckerTest, DocumentAnalysisRequestHandlerTest, XmlUpdateRequestHandlerTest, DocumentBuilderTest, TestValueSourceCache, PathHierarchyTokenizerFactoryTest, TestIndexingPerformance, MoreLikeThisHandlerTest, FieldAnalysisRequestHandlerTest, TestArbitraryIndexDir, FastVectorHighlighterTest, LoggingHandlerTest, RegexBoostProcessorTest, IndexSchemaTest, TestJmxIntegration, ReturnFieldsTest, UpdateRequestProcessorFactoryTest, JSONWriterTest, MBeansHandlerTest, UniqFieldsUpdateProcessorFactoryTest, JsonLoaderTest, TestPHPSerializedResponseWriter, CoreContainerCoreInitFailuresTest, TestLFUCache, SOLR749Test, TestQuerySenderListener, AlternateDirectoryTest, TestSolrIndexConfig, ResponseLogComponentTest, TestStressRecovery, TestMergePolicyConfig, TestSolrDeletionPolicy2, TestSearchPerf, NumericFieldsTest, MinimalSchemaTest, TestElisionMultitermQuery, TestFuzzyAnalyzedSuggestions, TestSolrCoreProperties, TestPostingsSolrHighlighter, TestPhraseSuggestions, SpellPossibilityIteratorTest, TestCharFilters, SynonymTokenizerTest, TestXIncludeConfig, EchoParamsTest, TestDFRSimilarityFactory, TestPerFieldSimilarity, TestLMDirichletSimilarityFactory, TestLMJelinekMercerSimilarityFactory, TestBM25SimilarityFactory, TestPluginEnable, TimeZoneUtilsTest, ResourceLoaderTest, ScriptEngineTest, URLClassifyProcessorTest, DateMathParserTest, ChaosMonkeyNothingIsSafeTest, PreAnalyzedFieldTest, PrimUtilsTest, SpellingQueryConverterTest, DOMUtilTest, RAMDirectoryFactoryTest, TestLRUCache, TestUtils, ZkNodePropsTest, SystemInfoHandlerTest, UUIDFieldTest, FileUtilsTest, TestRTGBase, SolrTestCaseJ4Test, ChaosMonkeyShardSplitTest]
[junit4:junit4] Completed in 69.46s, 1 test, 1 error <<< FAILURES!
[...truncated 40 lines...]
BUILD FAILED
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:385: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:365: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\build.xml:39: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\build.xml:181: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\solr\common-build.xml:437: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:1240: The following error occurred while executing this line:
C:\Users\JenkinsSlave\workspace\Lucene-Solr-trunk-Windows\lucene\common-build.xml:884: There were test failures: 296 suites, 1243 tests, 1 error, 1 failure, 18 ignored (12 assumptions)
Total time: 71 minutes 10 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.7.0_21 -XX:+UseCompressedOops -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure