You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2013/06/08 22:08:38 UTC
[JENKINS] Lucene-Solr-Tests-4.x-Java6 - Build # 1693 - Still
Failing
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java6/1693/
1 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeyShardSplitTest.testDistribSearch
Error Message:
Server at http://127.0.0.1:42127 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:42127 returned non ok status:500, message:Server Error
at __randomizedtesting.SeedInfo.seed([3AC8DEEB6F31307C:BB2E50F3186E5040]: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.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:616)
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:679)
Build Log:
[...truncated 9499 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.ChaosMonkeyShardSplitTest
[junit4:junit4] 2> 1416924 T3046 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4] 2> 1416929 T3046 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-ChaosMonkeyShardSplitTest-1370721772865
[junit4:junit4] 2> 1416930 T3046 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 1416931 T3047 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 1417032 T3046 oasc.ZkTestServer.run start zk server on port:42113
[junit4:junit4] 2> 1417033 T3046 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1417038 T3053 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7f8070c6 name:ZooKeeperConnection Watcher:127.0.0.1:42113 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1417038 T3046 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1417038 T3046 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 1417050 T3046 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1417056 T3055 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e35d46a name:ZooKeeperConnection Watcher:127.0.0.1:42113/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1417056 T3046 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1417057 T3046 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 1417060 T3046 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 1417069 T3046 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 1417071 T3046 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 1417074 T3046 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 1417075 T3046 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 1417091 T3046 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 1417091 T3046 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 1417204 T3046 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 1417205 T3046 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 1417211 T3046 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 1417212 T3046 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 1417221 T3046 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 1417222 T3046 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 1417229 T3046 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 1417230 T3046 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 1417233 T3046 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 1417234 T3046 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 1417237 T3046 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 1417237 T3046 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 1417240 T3046 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 1417241 T3046 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 1417500 T3046 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1417504 T3046 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:42119
[junit4:junit4] 2> 1417505 T3046 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1417506 T3046 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1417506 T3046 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370721773186
[junit4:junit4] 2> 1417507 T3046 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370721773186/solr.xml
[junit4:junit4] 2> 1417507 T3046 oasc.CoreContainer.<init> New CoreContainer 912587286
[junit4:junit4] 2> 1417508 T3046 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370721773186/'
[junit4:junit4] 2> 1417508 T3046 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370721773186/'
[junit4:junit4] 2> 1417623 T3046 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1417624 T3046 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1417624 T3046 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1417625 T3046 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1417625 T3046 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1417626 T3046 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1417626 T3046 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1417627 T3046 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1417627 T3046 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1417628 T3046 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1417643 T3046 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1417644 T3046 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:42113/solr
[junit4:junit4] 2> 1417645 T3046 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1417646 T3046 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1417648 T3066 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b4413d7 name:ZooKeeperConnection Watcher:127.0.0.1:42113 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1417649 T3046 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1417650 T3046 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1417660 T3046 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1417662 T3068 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@931cf00 name:ZooKeeperConnection Watcher:127.0.0.1:42113/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1417663 T3046 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1417665 T3046 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 1417674 T3046 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 1417678 T3046 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 1417680 T3046 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42119_
[junit4:junit4] 2> 1417687 T3046 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42119_
[junit4:junit4] 2> 1417691 T3046 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 1417708 T3046 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 1417710 T3046 oasc.Overseer.start Overseer (id=89831622107070467-127.0.0.1:42119_-n_0000000000) starting
[junit4:junit4] 2> 1417722 T3046 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 1417731 T3070 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 1417731 T3046 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 1417738 T3046 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 1417740 T3046 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1417743 T3069 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 1417747 T3071 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370721773186/collection1
[junit4:junit4] 2> 1417747 T3071 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 1417748 T3071 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1417748 T3071 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 1417750 T3071 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370721773186/collection1/'
[junit4:junit4] 2> 1417751 T3071 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370721773186/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1417752 T3071 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370721773186/collection1/lib/README' to classloader
[junit4:junit4] 2> 1417814 T3071 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 1417878 T3071 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1417979 T3071 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1417985 T3071 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 1418569 T3071 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1418573 T3071 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1418576 T3071 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1418581 T3071 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1418602 T3071 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1418602 T3071 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370721773186/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/control/data/
[junit4:junit4] 2> 1418603 T3071 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@52234265
[junit4:junit4] 2> 1418603 T3071 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1418604 T3071 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/control/data
[junit4:junit4] 2> 1418604 T3071 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/control/data/index/
[junit4:junit4] 2> 1418604 T3071 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1418607 T3071 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/control/data/index
[junit4:junit4] 2> 1418612 T3071 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/index3287232879tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@712dcc37),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1418613 T3071 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1418616 T3071 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1418616 T3071 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1418617 T3071 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1418617 T3071 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1418618 T3071 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1418618 T3071 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1418618 T3071 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1418619 T3071 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1418619 T3071 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1418629 T3071 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1418637 T3071 oass.SolrIndexSearcher.<init> Opening Searcher@1f3f0500 main
[junit4:junit4] 2> 1418637 T3071 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/control/data/tlog
[junit4:junit4] 2> 1418638 T3071 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1418639 T3071 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1418642 T3072 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1f3f0500 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1418643 T3071 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1418644 T3071 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1419246 T3069 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1419247 T3069 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42119_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42119"}
[junit4:junit4] 2> 1419247 T3069 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 1419247 T3069 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 1419251 T3068 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> 1419646 T3071 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1419646 T3071 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:42119 collection:control_collection shard:shard1
[junit4:junit4] 2> 1419647 T3071 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 1419662 T3071 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 1419664 T3071 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 1419665 T3071 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 1419665 T3071 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:42119/collection1/
[junit4:junit4] 2> 1419665 T3071 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 1419665 T3071 oasc.SyncStrategy.syncToMe http://127.0.0.1:42119/collection1/ has no replicas
[junit4:junit4] 2> 1419666 T3071 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:42119/collection1/
[junit4:junit4] 2> 1419666 T3071 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 1420755 T3069 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1420807 T3068 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> 1420855 T3071 oasc.ZkController.register We are http://127.0.0.1:42119/collection1/ and leader is http://127.0.0.1:42119/collection1/
[junit4:junit4] 2> 1420855 T3071 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:42119
[junit4:junit4] 2> 1420855 T3071 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 1420856 T3071 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 1420856 T3071 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1420858 T3071 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1420859 T3046 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4:junit4] 2> 1420859 T3046 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1420860 T3046 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1420877 T3046 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 1420878 T3046 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1420881 T3075 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@13a30389 name:ZooKeeperConnection Watcher:127.0.0.1:42113/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1420881 T3046 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1420882 T3046 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1420884 T3046 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 1421132 T3046 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1421135 T3046 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:42127
[junit4:junit4] 2> 1421136 T3046 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1421136 T3046 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1421137 T3046 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370721776820
[junit4:junit4] 2> 1421137 T3046 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370721776820/solr.xml
[junit4:junit4] 2> 1421138 T3046 oasc.CoreContainer.<init> New CoreContainer 1478820560
[junit4:junit4] 2> 1421139 T3046 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370721776820/'
[junit4:junit4] 2> 1421139 T3046 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370721776820/'
[junit4:junit4] 2> 1421250 T3046 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1421251 T3046 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1421251 T3046 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1421252 T3046 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1421252 T3046 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1421253 T3046 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1421253 T3046 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1421254 T3046 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1421254 T3046 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1421255 T3046 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1421272 T3046 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1421273 T3046 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:42113/solr
[junit4:junit4] 2> 1421273 T3046 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1421274 T3046 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1421276 T3086 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@42f2eca1 name:ZooKeeperConnection Watcher:127.0.0.1:42113 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1421277 T3046 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1421279 T3046 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1421291 T3046 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1421293 T3088 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7f52e604 name:ZooKeeperConnection Watcher:127.0.0.1:42113/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1421293 T3046 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1421304 T3046 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1422307 T3046 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42127_
[junit4:junit4] 2> 1422309 T3046 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42127_
[junit4:junit4] 2> 1422311 T3068 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> 1422312 T3075 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 1422312 T3088 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 1422313 T3068 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 1422325 T3089 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370721776820/collection1
[junit4:junit4] 2> 1422325 T3089 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 1422326 T3069 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1422326 T3089 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1422326 T3069 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:42119__collection1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42119_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42119"}
[junit4:junit4] 2> 1422326 T3089 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 1422329 T3089 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370721776820/collection1/'
[junit4:junit4] 2> 1422330 T3089 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370721776820/collection1/lib/README' to classloader
[junit4:junit4] 2> 1422331 T3089 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370721776820/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1422336 T3068 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> 1422336 T3075 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> 1422336 T3088 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> 1422386 T3089 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 1422449 T3089 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1422550 T3089 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1422556 T3089 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 1423134 T3089 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1423138 T3089 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1423141 T3089 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1423146 T3089 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1423167 T3089 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1423167 T3089 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370721776820/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty1/
[junit4:junit4] 2> 1423167 T3089 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@52234265
[junit4:junit4] 2> 1423168 T3089 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1423169 T3089 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty1
[junit4:junit4] 2> 1423169 T3089 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty1/index/
[junit4:junit4] 2> 1423169 T3089 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1423172 T3089 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty1/index
[junit4:junit4] 2> 1423177 T3089 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/index3287232880tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@15541539),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1423177 T3089 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1423180 T3089 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1423180 T3089 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1423181 T3089 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1423182 T3089 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1423182 T3089 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1423183 T3089 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1423183 T3089 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1423184 T3089 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1423184 T3089 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1423194 T3089 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1423202 T3089 oass.SolrIndexSearcher.<init> Opening Searcher@1b2b4391 main
[junit4:junit4] 2> 1423202 T3089 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty1/tlog
[junit4:junit4] 2> 1423203 T3089 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1423204 T3089 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1423208 T3090 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1b2b4391 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1423210 T3089 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1423211 T3089 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1423840 T3069 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1423841 T3069 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42127_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42127"}
[junit4:junit4] 2> 1423841 T3069 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 1423841 T3069 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 1423860 T3068 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> 1423860 T3075 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> 1423860 T3088 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> 1424214 T3089 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1424214 T3089 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:42127 collection:collection1 shard:shard1
[junit4:junit4] 2> 1424215 T3089 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 1424230 T3089 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 1424232 T3089 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 1424233 T3089 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 1424233 T3089 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:42127/collection1/
[junit4:junit4] 2> 1424233 T3089 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 1424233 T3089 oasc.SyncStrategy.syncToMe http://127.0.0.1:42127/collection1/ has no replicas
[junit4:junit4] 2> 1424234 T3089 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:42127/collection1/
[junit4:junit4] 2> 1424234 T3089 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 1425364 T3069 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1425395 T3068 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> 1425395 T3088 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> 1425395 T3075 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> 1425412 T3089 oasc.ZkController.register We are http://127.0.0.1:42127/collection1/ and leader is http://127.0.0.1:42127/collection1/
[junit4:junit4] 2> 1425412 T3089 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:42127
[junit4:junit4] 2> 1425412 T3089 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 1425412 T3089 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 1425412 T3089 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1425414 T3089 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1425415 T3046 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4:junit4] 2> 1425416 T3046 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1425416 T3046 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1425677 T3046 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1425681 T3046 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:42134
[junit4:junit4] 2> 1425681 T3046 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1425682 T3046 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1425682 T3046 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370721781366
[junit4:junit4] 2> 1425683 T3046 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370721781366/solr.xml
[junit4:junit4] 2> 1425683 T3046 oasc.CoreContainer.<init> New CoreContainer 1429626245
[junit4:junit4] 2> 1425684 T3046 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370721781366/'
[junit4:junit4] 2> 1425685 T3046 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370721781366/'
[junit4:junit4] 2> 1425794 T3046 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1425795 T3046 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1425795 T3046 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1425796 T3046 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1425796 T3046 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1425797 T3046 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1425797 T3046 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1425798 T3046 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1425798 T3046 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1425799 T3046 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1425814 T3046 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1425815 T3046 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:42113/solr
[junit4:junit4] 2> 1425815 T3046 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1425816 T3046 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1425819 T3102 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@11c19607 name:ZooKeeperConnection Watcher:127.0.0.1:42113 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1425819 T3046 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1425821 T3046 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1425828 T3046 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1425830 T3104 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7eea59b2 name:ZooKeeperConnection Watcher:127.0.0.1:42113/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1425830 T3046 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1425841 T3046 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1426845 T3046 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42134_
[junit4:junit4] 2> 1426847 T3046 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42134_
[junit4:junit4] 2> 1426850 T3068 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> 1426850 T3088 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> 1426850 T3104 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 1426850 T3075 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> 1426851 T3068 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 1426862 T3088 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 1426863 T3075 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 1426868 T3105 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370721781366/collection1
[junit4:junit4] 2> 1426869 T3105 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 1426869 T3105 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1426870 T3105 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 1426871 T3105 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370721781366/collection1/'
[junit4:junit4] 2> 1426872 T3105 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370721781366/collection1/lib/README' to classloader
[junit4:junit4] 2> 1426873 T3105 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370721781366/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1426905 T3069 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1426906 T3069 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:42127__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42127_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42127"}
[junit4:junit4] 2> 1426916 T3068 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> 1426916 T3075 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> 1426916 T3088 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> 1426916 T3104 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> 1426929 T3105 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 1427000 T3105 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1427101 T3105 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1427107 T3105 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 1427687 T3105 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1427691 T3105 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1427694 T3105 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1427698 T3105 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1427717 T3105 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1427718 T3105 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370721781366/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty2/
[junit4:junit4] 2> 1427718 T3105 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@52234265
[junit4:junit4] 2> 1427718 T3105 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1427719 T3105 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty2
[junit4:junit4] 2> 1427719 T3105 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty2/index/
[junit4:junit4] 2> 1427719 T3105 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1427721 T3105 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty2/index
[junit4:junit4] 2> 1427725 T3105 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/index3287232881tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@192451f7),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1427725 T3105 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1427727 T3105 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1427727 T3105 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1427728 T3105 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1427728 T3105 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1427728 T3105 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1427729 T3105 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1427729 T3105 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1427729 T3105 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1427730 T3105 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1427736 T3105 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1427741 T3105 oass.SolrIndexSearcher.<init> Opening Searcher@35412d73 main
[junit4:junit4] 2> 1427741 T3105 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty2/tlog
[junit4:junit4] 2> 1427742 T3105 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1427742 T3105 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1427745 T3106 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@35412d73 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1427747 T3105 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1427747 T3105 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1428425 T3069 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1428426 T3069 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42134_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42134"}
[junit4:junit4] 2> 1428426 T3069 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 1428426 T3069 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 1428440 T3068 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> 1428440 T3088 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> 1428440 T3104 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> 1428440 T3075 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> 1428749 T3105 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1428749 T3105 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:42134 collection:collection1 shard:shard2
[junit4:junit4] 2> 1428750 T3105 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 1428773 T3105 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 1428789 T3105 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 1428789 T3105 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 1428789 T3105 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:42134/collection1/
[junit4:junit4] 2> 1428790 T3105 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 1428790 T3105 oasc.SyncStrategy.syncToMe http://127.0.0.1:42134/collection1/ has no replicas
[junit4:junit4] 2> 1428790 T3105 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:42134/collection1/
[junit4:junit4] 2> 1428790 T3105 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 1429949 T3069 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1430057 T3068 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> 1430057 T3104 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> 1430057 T3088 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> 1430057 T3075 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> 1430079 T3105 oasc.ZkController.register We are http://127.0.0.1:42134/collection1/ and leader is http://127.0.0.1:42134/collection1/
[junit4:junit4] 2> 1430079 T3105 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:42134
[junit4:junit4] 2> 1430079 T3105 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 1430079 T3105 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 1430080 T3105 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1430082 T3105 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1430083 T3046 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4:junit4] 2> 1430083 T3046 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1430084 T3046 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1430362 T3046 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1430365 T3046 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:53377
[junit4:junit4] 2> 1430366 T3046 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1430367 T3046 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1430367 T3046 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370721786038
[junit4:junit4] 2> 1430368 T3046 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370721786038/solr.xml
[junit4:junit4] 2> 1430368 T3046 oasc.CoreContainer.<init> New CoreContainer 1087702797
[junit4:junit4] 2> 1430369 T3046 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370721786038/'
[junit4:junit4] 2> 1430369 T3046 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370721786038/'
[junit4:junit4] 2> 1430483 T3046 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1430483 T3046 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1430484 T3046 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1430484 T3046 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1430485 T3046 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1430485 T3046 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1430486 T3046 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1430486 T3046 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1430487 T3046 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1430487 T3046 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1430504 T3046 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1430505 T3046 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:42113/solr
[junit4:junit4] 2> 1430506 T3046 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1430507 T3046 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1430510 T3118 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@989b821 name:ZooKeeperConnection Watcher:127.0.0.1:42113 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1430510 T3046 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1430529 T3046 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1430541 T3046 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1430543 T3120 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2ba6e652 name:ZooKeeperConnection Watcher:127.0.0.1:42113/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1430543 T3046 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1430558 T3046 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1431561 T3046 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:53377_
[junit4:junit4] 2> 1431563 T3046 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:53377_
[junit4:junit4] 2> 1431565 T3068 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> 1431565 T3088 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> 1431565 T3075 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> 1431566 T3120 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1431566 T3104 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1431567 T3069 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1431567 T3104 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1431574 T3088 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1431574 T3069 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:42134__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42134_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42134"}
[junit4:junit4] 2> 1431574 T3075 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1431580 T3121 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370721786038/collection1
[junit4:junit4] 2> 1431580 T3121 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 1431582 T3121 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1431582 T3121 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 1431583 T3075 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1431583 T3104 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1431583 T3120 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1431583 T3088 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1431585 T3121 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370721786038/collection1/'
[junit4:junit4] 2> 1431586 T3121 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370721786038/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1431587 T3121 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370721786038/collection1/lib/README' to classloader
[junit4:junit4] 2> 1431587 T3068 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1431587 T3068 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1431636 T3121 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 1431695 T3121 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1431796 T3121 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1431802 T3121 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 1432359 T3121 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1432364 T3121 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1432366 T3121 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1432371 T3121 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1432393 T3121 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1432393 T3121 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370721786038/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty3/
[junit4:junit4] 2> 1432394 T3121 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@52234265
[junit4:junit4] 2> 1432394 T3121 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1432395 T3121 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty3
[junit4:junit4] 2> 1432395 T3121 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty3/index/
[junit4:junit4] 2> 1432395 T3121 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1432398 T3121 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty3/index
[junit4:junit4] 2> 1432429 T3121 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/index3287232882tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@61bfc8d5),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1432430 T3121 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1432433 T3121 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1432433 T3121 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1432434 T3121 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1432434 T3121 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1432435 T3121 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1432435 T3121 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1432436 T3121 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1432436 T3121 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1432437 T3121 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1432446 T3121 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1432455 T3121 oass.SolrIndexSearcher.<init> Opening Searcher@6d5aa30c main
[junit4:junit4] 2> 1432455 T3121 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty3/tlog
[junit4:junit4] 2> 1432456 T3121 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1432457 T3121 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1432461 T3122 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6d5aa30c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1432463 T3121 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1432464 T3121 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1433088 T3069 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1433089 T3069 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:53377_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53377"}
[junit4:junit4] 2> 1433089 T3069 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 1433089 T3069 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 1433102 T3068 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1433102 T3075 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1433102 T3088 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1433102 T3120 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1433102 T3104 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1433466 T3121 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1433466 T3121 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:53377 collection:collection1 shard:shard1
[junit4:junit4] 2> 1433469 T3121 oasc.ZkController.register We are http://127.0.0.1:53377/collection1/ and leader is http://127.0.0.1:42127/collection1/
[junit4:junit4] 2> 1433469 T3121 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:53377
[junit4:junit4] 2> 1433469 T3121 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 1433469 T3121 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C963 name=collection1 org.apache.solr.core.SolrCore@48a61000 url=http://127.0.0.1:53377/collection1 node=127.0.0.1:53377_ C963_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:53377_, base_url=http://127.0.0.1:53377}
[junit4:junit4] 2> 1433470 T3123 C963 P53377 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 1433470 T3121 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1433472 T3123 C963 P53377 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 1433472 T3123 C963 P53377 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 1433472 T3123 C963 P53377 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1433472 T3046 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4:junit4] 2> 1433473 T3046 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1433473 T3123 C963 P53377 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1433474 T3046 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1433497 T3078 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:53377__collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 1433746 T3046 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1433749 T3046 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:43881
[junit4:junit4] 2> 1433750 T3046 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1433751 T3046 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1433751 T3046 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370721789431
[junit4:junit4] 2> 1433752 T3046 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370721789431/solr.xml
[junit4:junit4] 2> 1433752 T3046 oasc.CoreContainer.<init> New CoreContainer 148821529
[junit4:junit4] 2> 1433753 T3046 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370721789431/'
[junit4:junit4] 2> 1433753 T3046 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370721789431/'
[junit4:junit4] 2> 1433862 T3046 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1433863 T3046 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1433863 T3046 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1433864 T3046 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1433864 T3046 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1433865 T3046 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1433865 T3046 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1433866 T3046 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1433866 T3046 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1433867 T3046 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1433881 T3046 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1433882 T3046 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:42113/solr
[junit4:junit4] 2> 1433882 T3046 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1433884 T3046 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1433887 T3135 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6059eaef name:ZooKeeperConnection Watcher:127.0.0.1:42113 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1433887 T3046 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1433902 T3046 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1433912 T3046 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1433919 T3137 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@45fad5ad name:ZooKeeperConnection Watcher:127.0.0.1:42113/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1433920 T3046 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1433932 T3046 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1434606 T3069 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1434607 T3069 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:53377__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:53377_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53377"}
[junit4:junit4] 2> 1434639 T3068 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1434639 T3104 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1434639 T3120 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1434639 T3137 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1434639 T3088 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1434639 T3075 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1434935 T3046 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:43881_
[junit4:junit4] 2> 1434937 T3046 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:43881_
[junit4:junit4] 2> 1434963 T3068 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1434963 T3137 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1434963 T3088 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1434963 T3075 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1434963 T3120 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1434963 T3104 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1434964 T3120 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1434964 T3068 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1434964 T3104 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1434965 T3137 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1434966 T3088 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1434966 T3075 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1434971 T3138 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370721789431/collection1
[junit4:junit4] 2> 1434971 T3138 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 1434972 T3138 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1434972 T3138 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 1434974 T3138 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370721789431/collection1/'
[junit4:junit4] 2> 1434975 T3138 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370721789431/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1434976 T3138 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370721789431/collection1/lib/README' to classloader
[junit4:junit4] 2> 1435026 T3138 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 1435084 T3138 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1435186 T3138 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1435192 T3138 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 1435500 T3078 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:53377__collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 1435500 T3078 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:53377__collection1&state=recovering&nodeName=127.0.0.1:53377_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2003
[junit4:junit4] 2> 1436211 T3138 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1436215 T3138 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1436217 T3138 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1436222 T3138 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1436243 T3138 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1436243 T3138 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370721789431/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty4/
[junit4:junit4] 2> 1436244 T3138 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@52234265
[junit4:junit4] 2> 1436244 T3138 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1436245 T3138 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty4
[junit4:junit4] 2> 1436245 T3138 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty4/index/
[junit4:junit4] 2> 1436245 T3138 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1436247 T3138 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty4/index
[junit4:junit4] 2> 1436281 T3138 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/index3287232883tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@3b3f24bd),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1436281 T3138 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1436284 T3138 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1436284 T3138 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1436285 T3138 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1436286 T3138 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1436286 T3138 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1436287 T3138 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1436287 T3138 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1436288 T3138 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1436288 T3138 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1436297 T3138 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1436306 T3138 oass.SolrIndexSearcher.<init> Opening Searcher@47f47a0d main
[junit4:junit4] 2> 1436306 T3138 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty4/tlog
[junit4:junit4] 2> 1436307 T3138 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1436308 T3138 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1436312 T3139 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@47f47a0d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1436314 T3138 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1436314 T3138 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> ASYNC NEW_CORE C964 name=collection1 org.apache.solr.core.SolrCore@48a61000 url=http://127.0.0.1:53377/collection1 node=127.0.0.1:53377_ C964_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:53377_, base_url=http://127.0.0.1:53377}
[junit4:junit4] 2> 1437502 T3123 C964 P53377 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:42127/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 1437502 T3123 C964 P53377 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:53377 START replicas=[http://127.0.0.1:42127/collection1/] nUpdates=100
[junit4:junit4] 2> 1437503 T3123 C964 P53377 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 1437504 T3123 C964 P53377 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 1437504 T3123 C964 P53377 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 1437504 T3123 C964 P53377 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 1437504 T3123 C964 P53377 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 1437505 T3123 C964 P53377 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:42127/collection1/. core=collection1
[junit4:junit4] 2> 1437505 T3123 C964 P53377 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C965 name=collection1 org.apache.solr.core.SolrCore@62958e11 url=http://127.0.0.1:42127/collection1 node=127.0.0.1:42127_ C965_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:42127_, base_url=http://127.0.0.1:42127, leader=true}
[junit4:junit4] 2> 1437511 T3079 C965 P42127 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 1437522 T3080 C965 P42127 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1437525 T3080 C965 P42127 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/index3287232880tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@15541539),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1437526 T3080 C965 P42127 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1437528 T3080 C965 P42127 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/index3287232880tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@15541539),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/index3287232880tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@15541539),segFN=segments_2,generation=2}
[junit4:junit4] 2> 1437529 T3080 C965 P42127 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1437530 T3080 C965 P42127 oass.SolrIndexSearcher.<init> Opening Searcher@5ec64aa3 realtime
[junit4:junit4] 2> 1437530 T3080 C965 P42127 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1437531 T3080 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 10
[junit4:junit4] 2> 1437531 T3123 C964 P53377 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 1437532 T3123 C964 P53377 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 1437534 T3081 C965 P42127 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 1437534 T3081 C965 P42127 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> 1437535 T3123 C964 P53377 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 1437535 T3123 C964 P53377 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 1437535 T3123 C964 P53377 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 1437539 T3081 C965 P42127 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=1
[junit4:junit4] 2> 1437539 T3123 C964 P53377 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 1437540 T3123 C964 P53377 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty3/index.20130608210313475
[junit4:junit4] 2> 1437541 T3123 C964 P53377 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@f0b90f5 lockFactory=org.apache.lucene.store.NativeFSLockFactory@10b3bf3f) fullCopy=false
[junit4:junit4] 2> 1437543 T3081 C965 P42127 oasc.SolrCore.execute [collection1] webapp= path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 1437545 T3123 C964 P53377 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 1437546 T3123 C964 P53377 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 1437546 T3123 C964 P53377 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 1437550 T3123 C964 P53377 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/index3287232882tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@61bfc8d5),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/index3287232882tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@61bfc8d5),segFN=segments_2,generation=2}
[junit4:junit4] 2> 1437550 T3123 C964 P53377 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1437550 T3123 C964 P53377 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 1437551 T3123 C964 P53377 oass.SolrIndexSearcher.<init> Opening Searcher@2e718cf2 main
[junit4:junit4] 2> 1437552 T3122 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2e718cf2 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1437553 T3123 C964 P53377 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty3/index.20130608210313475 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty3/index.20130608210313475;done=true>>]
[junit4:junit4] 2> 1437553 T3123 C964 P53377 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty3/index.20130608210313475
[junit4:junit4] 2> 1437553 T3123 C964 P53377 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty3/index.20130608210313475
[junit4:junit4] 2> 1437553 T3123 C964 P53377 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 1437553 T3123 C964 P53377 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 1437554 T3123 C964 P53377 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 1437554 T3123 C964 P53377 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1437555 T3123 C964 P53377 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 1437656 T3069 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1437657 T3069 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:43881_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:43881"}
[junit4:junit4] 2> 1437657 T3069 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 1437657 T3069 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 1437660 T3069 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:53377__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:53377_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:53377"}
[junit4:junit4] 2> 1437672 T3068 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1437672 T3104 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1437672 T3137 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1437672 T3120 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1437672 T3088 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1437672 T3075 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1438318 T3138 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1438318 T3138 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:43881 collection:collection1 shard:shard2
[junit4:junit4] 2> 1438321 T3138 oasc.ZkController.register We are http://127.0.0.1:43881/collection1/ and leader is http://127.0.0.1:42134/collection1/
[junit4:junit4] 2> 1438322 T3138 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:43881
[junit4:junit4] 2> 1438322 T3138 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 1438322 T3138 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C966 name=collection1 org.apache.solr.core.SolrCore@70b053f8 url=http://127.0.0.1:43881/collection1 node=127.0.0.1:43881_ C966_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:43881_, base_url=http://127.0.0.1:43881}
[junit4:junit4] 2> 1438322 T3142 C966 P43881 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 1438323 T3138 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1438323 T3142 C966 P43881 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 1438324 T3142 C966 P43881 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 1438324 T3142 C966 P43881 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1438325 T3046 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4:junit4] 2> 1438325 T3046 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1438326 T3142 C966 P43881 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1438326 T3046 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1438353 T3046 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1438355 T3046 oasc.AbstractFullDistribZkTestBase.waitForThingsToLevelOut Wait for recoveries to finish - wait 15 for each attempt
[junit4:junit4] 2> 1438355 T3094 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:43881__collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 1438355 T3046 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):15
[junit4:junit4] 2> 1438357 T3046 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1439187 T3069 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1439188 T3069 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:43881__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:43881_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:43881"}
[junit4:junit4] 2> 1439204 T3068 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1439204 T3137 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1439204 T3120 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1439204 T3104 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1439204 T3075 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1439204 T3088 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1439357 T3094 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:43881__collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 1439357 T3094 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:43881__collection1&state=recovering&nodeName=127.0.0.1:43881_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1002
[junit4:junit4] 2> 1439358 T3046 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1440360 T3046 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> C966_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:43881_, base_url=http://127.0.0.1:43881}
[junit4:junit4] 2> 1441359 T3142 C966 P43881 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:42134/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 1441359 T3142 C966 P43881 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:43881 START replicas=[http://127.0.0.1:42134/collection1/] nUpdates=100
[junit4:junit4] 2> 1441360 T3142 C966 P43881 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 1441360 T3142 C966 P43881 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 1441360 T3142 C966 P43881 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 1441360 T3142 C966 P43881 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 1441360 T3142 C966 P43881 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 1441361 T3142 C966 P43881 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:42134/collection1/. core=collection1
[junit4:junit4] 2> 1441361 T3142 C966 P43881 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1441362 T3046 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> ASYNC NEW_CORE C967 name=collection1 org.apache.solr.core.SolrCore@272c7ed6 url=http://127.0.0.1:42134/collection1 node=127.0.0.1:42134_ C967_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:42134_, base_url=http://127.0.0.1:42134, leader=true}
[junit4:junit4] 2> 1441372 T3095 C967 P42134 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 1441378 T3096 C967 P42134 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1441381 T3096 C967 P42134 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/index3287232881tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@192451f7),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1441382 T3096 C967 P42134 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1441385 T3096 C967 P42134 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/index3287232881tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@192451f7),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/index3287232881tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@192451f7),segFN=segments_2,generation=2}
[junit4:junit4] 2> 1441385 T3096 C967 P42134 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1441386 T3096 C967 P42134 oass.SolrIndexSearcher.<init> Opening Searcher@357c3d70 realtime
[junit4:junit4] 2> 1441386 T3096 C967 P42134 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1441387 T3096 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 10
[junit4:junit4] 2> 1441388 T3142 C966 P43881 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 1441388 T3142 C966 P43881 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 1441390 T3097 C967 P42134 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 1441390 T3097 C967 P42134 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> 1441391 T3142 C966 P43881 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 1441391 T3142 C966 P43881 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 1441391 T3142 C966 P43881 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 1441394 T3097 C967 P42134 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=1
[junit4:junit4] 2> 1441394 T3142 C966 P43881 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 1441396 T3142 C966 P43881 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty4/index.20130608210317330
[junit4:junit4] 2> 1441396 T3142 C966 P43881 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@609c1beb lockFactory=org.apache.lucene.store.NativeFSLockFactory@251244c9) fullCopy=false
[junit4:junit4] 2> 1441399 T3097 C967 P42134 oasc.SolrCore.execute [collection1] webapp= path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 1441401 T3142 C966 P43881 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 1441402 T3142 C966 P43881 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 1441402 T3142 C966 P43881 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 1441406 T3142 C966 P43881 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/index3287232883tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@3b3f24bd),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/index3287232883tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@3b3f24bd),segFN=segments_2,generation=2}
[junit4:junit4] 2> 1441406 T3142 C966 P43881 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1441407 T3142 C966 P43881 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 1441407 T3142 C966 P43881 oass.SolrIndexSearcher.<init> Opening Searcher@78704204 main
[junit4:junit4] 2> 1441408 T3139 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@78704204 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1441409 T3142 C966 P43881 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty4/index.20130608210317330 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty4/index.20130608210317330;done=true>>]
[junit4:junit4] 2> 1441409 T3142 C966 P43881 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty4/index.20130608210317330
[junit4:junit4] 2> 1441409 T3142 C966 P43881 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty4/index.20130608210317330
[junit4:junit4] 2> 1441410 T3142 C966 P43881 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 1441410 T3142 C966 P43881 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 1441410 T3142 C966 P43881 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 1441410 T3142 C966 P43881 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1441412 T3142 C966 P43881 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 1442209 T3069 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1442210 T3069 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:43881__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:43881_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:43881"}
[junit4:junit4] 2> 1442222 T3068 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1442222 T3088 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1442222 T3137 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1442222 T3120 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1442222 T3104 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1442222 T3075 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1442364 T3046 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1442365 T3046 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: collection1
[junit4:junit4] 2> ASYNC NEW_CORE C968 name=collection1 org.apache.solr.core.SolrCore@35c0f964 url=http://127.0.0.1:42119/collection1 node=127.0.0.1:42119_ C968_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:42119_, base_url=http://127.0.0.1:42119, leader=true}
[junit4:junit4] 2> 1442377 T3058 C968 P42119 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1442382 T3058 C968 P42119 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/index3287232879tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@712dcc37),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1442382 T3058 C968 P42119 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1442384 T3058 C968 P42119 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/index3287232879tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@712dcc37),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/index3287232879tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@712dcc37),segFN=segments_2,generation=2}
[junit4:junit4] 2> 1442385 T3058 C968 P42119 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1442386 T3058 C968 P42119 oass.SolrIndexSearcher.<init> Opening Searcher@11ee9c75 main
[junit4:junit4] 2> 1442386 T3058 C968 P42119 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1442387 T3072 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@11ee9c75 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1442390 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 13
[junit4:junit4] 2> 1442401 T3098 C967 P42134 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1442404 T3098 C967 P42134 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/index3287232881tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@192451f7),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/index3287232881tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@192451f7),segFN=segments_3,generation=3}
[junit4:junit4] 2> 1442404 T3098 C967 P42134 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 1442405 T3098 C967 P42134 oass.SolrIndexSearcher.<init> Opening Searcher@3080dfc0 main
[junit4:junit4] 2> 1442405 T3098 C967 P42134 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1442406 T3106 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3080dfc0 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1442407 T3098 C967 P42134 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:42127/collection1/, StdNode: http://127.0.0.1:53377/collection1/, StdNode: http://127.0.0.1:43881/collection1/] params:commit_end_point=true&commit=true&softCommit=false&waitSearcher=true&expungeDeletes=false
[junit4:junit4] 2> 1442409 T3082 C965 P42127 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1442413 T3082 C965 P42127 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/index3287232880tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@15541539),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/index3287232880tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@15541539),segFN=segments_3,generation=3}
[junit4:junit4] 2> 1442414 T3082 C965 P42127 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 1442414 T3082 C965 P42127 oass.SolrIndexSearcher.<init> Opening Searcher@6cf0c7f5 main
[junit4:junit4] 2> 1442415 T3082 C965 P42127 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1442416 T3090 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6cf0c7f5 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1442416 T3082 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 7
[junit4:junit4] 2> C966_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:43881_, base_url=http://127.0.0.1:43881}
[junit4:junit4] 2> 1442426 T3127 C966 P43881 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> C964_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:53377_, base_url=http://127.0.0.1:53377}
[junit4:junit4] 2> 1442426 T3110 C964 P53377 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1442430 T3127 C966 P43881 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/index3287232883tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@3b3f24bd),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/index3287232883tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@3b3f24bd),segFN=segments_3,generation=3}
[junit4:junit4] 2> 1442430 T3127 C966 P43881 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 1442431 T3110 C964 P53377 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/index3287232882tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@61bfc8d5),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/index3287232882tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@61bfc8d5),segFN=segments_3,generation=3}
[junit4:junit4] 2> 1442431 T3127 C966 P43881 oass.SolrIndexSearcher.<init> Opening Searcher@34c52daf main
[junit4:junit4] 2> 1442432 T3110 C964 P53377 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 1442432 T3127 C966 P43881 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1442433 T3139 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@34c52daf main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1442433 T3110 C964 P53377 oass.SolrIndexSearcher.<init> Opening Searcher@16658b46 main
[junit4:junit4] 2> 1442433 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 7
[junit4:junit4] 2> 1442434 T3110 C964 P53377 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1442434 T3122 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@16658b46 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1442435 T3110 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 9
[junit4:junit4] 2> 1442435 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 34
[junit4:junit4] 2> 1442437 T3046 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1442439 T3083 C965 P42127 oasc.SolrCore.execute [collection1] webapp= path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4] 2> 1442441 T3111 C964 P53377 oasc.SolrCore.execute [collection1] webapp= path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4] 2> 1442443 T3099 C967 P42134 oasc.SolrCore.execute [collection1] webapp= path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4] 2> 1442445 T3128 C966 P43881 oasc.SolrCore.execute [collection1] webapp= path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4] 2> 1444450 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1437305982559453184)} 0 2
[junit4:junit4] 2> 1444459 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={update.distrib=FROMLEADER&_version_=-1437305982563647488&update.from=http://127.0.0.1:42134/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1437305982563647488)} 0 2
[junit4:junit4] 2> 1444462 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={update.distrib=FROMLEADER&_version_=-1437305982567841792&update.from=http://127.0.0.1:42127/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1437305982567841792)} 0 2
[junit4:junit4] 2> 1444462 T3082 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={update.distrib=TOLEADER&wt=javabin&version=2} {deleteByQuery=*:* (-1437305982567841792)} 0 5
[junit4:junit4] 2> 1444463 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1437305982563647488)} 0 10
[junit4:junit4] 2> 1444468 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[0 (1437305982577278976)]} 0 2
[junit4:junit4] 2> 1444480 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[0 (1437305982585667584)]} 0 2
[junit4:junit4] 2> 1444481 T3082 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[0 (1437305982585667584)]} 0 7
[junit4:junit4] 2> 1444482 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[0]} 0 11
[junit4:junit4] 2> 1444485 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[1 (1437305982596153344)]} 0 1
[junit4:junit4] 2> 1444493 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[1 (1437305982601396224)]} 0 1
[junit4:junit4] 2> 1444493 T3082 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[1 (1437305982601396224)]} 0 4
[junit4:junit4] 2> 1444494 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[1]} 0 7
[junit4:junit4] 2> 1444498 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[2 (1437305982609784832)]} 0 1
[junit4:junit4] 2> 1444507 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[2 (1437305982613979136)]} 0 2
[junit4:junit4] 2> 1444508 T3100 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[2 (1437305982613979136)]} 0 7
[junit4:junit4] 2> 1444508 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[2]} 0 9
[junit4:junit4] 2> 1444511 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[3 (1437305982624464896)]} 0 0
[junit4:junit4] 2> 1444520 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[3 (1437305982630756352)]} 0 0
[junit4:junit4] 2> 1444521 T3100 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[3 (1437305982630756352)]} 0 4
[junit4:junit4] 2> 1444522 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[3]} 0 8
[junit4:junit4] 2> 1444525 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[4 (1437305982638096384)]} 0 1
[junit4:junit4] 2> 1444532 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[4 (1437305982642290688)]} 0 1
[junit4:junit4] 2> 1444532 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[4 (1437305982642290688)]} 0 4
[junit4:junit4] 2> 1444535 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[5 (1437305982649630720)]} 0 0
[junit4:junit4] 2> 1444542 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[5 (1437305982652776448)]} 0 1
[junit4:junit4] 2> 1444542 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[5 (1437305982652776448)]} 0 4
[junit4:junit4] 2> 1444545 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[6 (1437305982660116480)]} 0 0
[junit4:junit4] 2> 1444551 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[6 (1437305982663262208)]} 0 0
[junit4:junit4] 2> 1444552 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[6 (1437305982663262208)]} 0 4
[junit4:junit4] 2> 1444556 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[7 (1437305982670602240)]} 0 1
[junit4:junit4] 2> 1444564 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[7 (1437305982675845120)]} 0 1
[junit4:junit4] 2> 1444564 T3100 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[7 (1437305982675845120)]} 0 4
[junit4:junit4] 2> 1444565 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[7]} 0 7
[junit4:junit4] 2> 1444568 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[8 (1437305982684233728)]} 0 0
[junit4:junit4] 2> 1444575 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[8 (1437305982687379456)]} 0 1
[junit4:junit4] 2> 1444575 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[8 (1437305982687379456)]} 0 4
[junit4:junit4] 2> 1444578 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[9 (1437305982694719488)]} 0 0
[junit4:junit4] 2> 1444584 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[9 (1437305982697865216)]} 0 0
[junit4:junit4] 2> 1444585 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[9 (1437305982697865216)]} 0 4
[junit4:junit4] 2> 1444589 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10 (1437305982705205248)]} 0 1
[junit4:junit4] 2> 1444596 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10 (1437305982709399552)]} 0 1
[junit4:junit4] 2> 1444596 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10 (1437305982709399552)]} 0 4
[junit4:junit4] 2> 1444599 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[11 (1437305982716739584)]} 0 0
[junit4:junit4] 2> 1444607 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[11 (1437305982721982464)]} 0 0
[junit4:junit4] 2> 1444608 T3082 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[11 (1437305982721982464)]} 0 4
[junit4:junit4] 2> 1444609 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[11]} 0 7
[junit4:junit4] 2> 1444612 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[12 (1437305982729322496)]} 0 1
[junit4:junit4] 2> 1444620 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[12 (1437305982735613952)]} 0 0
[junit4:junit4] 2> 1444621 T3082 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[12 (1437305982735613952)]} 0 4
[junit4:junit4] 2> 1444622 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[12]} 0 7
[junit4:junit4] 2> 1444624 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[13 (1437305982742953984)]} 0 0
[junit4:junit4] 2> 1444631 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[13 (1437305982746099712)]} 0 1
[junit4:junit4] 2> 1444631 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[13 (1437305982746099712)]} 0 4
[junit4:junit4] 2> 1444634 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[14 (1437305982753439744)]} 0 0
[junit4:junit4] 2> 1444640 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[14 (1437305982756585472)]} 0 0
[junit4:junit4] 2> 1444641 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[14 (1437305982756585472)]} 0 4
[junit4:junit4] 2> 1444644 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[15 (1437305982763925504)]} 0 0
[junit4:junit4] 2> 1444651 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[15 (1437305982767071232)]} 0 1
[junit4:junit4] 2> 1444651 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[15 (1437305982767071232)]} 0 4
[junit4:junit4] 2> 1444654 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[16 (1437305982774411264)]} 0 0
[junit4:junit4] 2> 1444661 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[16 (1437305982777556992)]} 0 1
[junit4:junit4] 2> 1444661 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[16 (1437305982777556992)]} 0 4
[junit4:junit4] 2> 1444664 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[17 (1437305982784897024)]} 0 0
[junit4:junit4] 2> 1444672 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[17 (1437305982788042752)]} 0 1
[junit4:junit4] 2> 1444673 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[17 (1437305982788042752)]} 0 6
[junit4:junit4] 2> 1444677 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[18 (1437305982797479936)]} 0 1
[junit4:junit4] 2> 1444684 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[18 (1437305982801674240)]} 0 1
[junit4:junit4] 2> 1444685 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[18 (1437305982801674240)]} 0 5
[junit4:junit4] 2> 1444689 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[19 (1437305982810062848)]} 0 1
[junit4:junit4] 2> 1444698 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[19 (1437305982816354304)]} 0 1
[junit4:junit4] 2> 1444699 T3100 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[19 (1437305982816354304)]} 0 5
[junit4:junit4] 2> 1444700 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[19]} 0 9
[junit4:junit4] 2> 1444703 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[20 (1437305982824742912)]} 0 1
[junit4:junit4] 2> 1444711 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[20 (1437305982829985792)]} 0 1
[junit4:junit4] 2> 1444711 T3082 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[20 (1437305982829985792)]} 0 4
[junit4:junit4] 2> 1444712 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[20]} 0 7
[junit4:junit4] 2> 1444716 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[21 (1437305982838374400)]} 0 1
[junit4:junit4] 2> 1444724 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[21 (1437305982843617280)]} 0 1
[junit4:junit4] 2> 1444724 T3100 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[21 (1437305982843617280)]} 0 4
[junit4:junit4] 2> 1444725 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[21]} 0 7
[junit4:junit4] 2> 1444728 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[22 (1437305982852005888)]} 0 0
[junit4:junit4] 2> 1444749 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[22 (1437305982857248768)]} 0 1
[junit4:junit4] 2> 1444750 T3082 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[22 (1437305982857248768)]} 0 17
[junit4:junit4] 2> 1444750 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[22]} 0 19
[junit4:junit4] 2> 1444753 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[23 (1437305982878220288)]} 0 0
[junit4:junit4] 2> 1444761 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[23 (1437305982883463168)]} 0 0
[junit4:junit4] 2> 1444762 T3100 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[23 (1437305982883463168)]} 0 4
[junit4:junit4] 2> 1444763 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[23]} 0 7
[junit4:junit4] 2> 1444766 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[24 (1437305982891851776)]} 0 0
[junit4:junit4] 2> 1444773 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[24 (1437305982894997504)]} 0 1
[junit4:junit4] 2> 1444773 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[24 (1437305982894997504)]} 0 4
[junit4:junit4] 2> 1444776 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[25 (1437305982902337536)]} 0 0
[junit4:junit4] 2> 1444782 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[25 (1437305982905483264)]} 0 0
[junit4:junit4] 2> 1444783 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[25 (1437305982905483264)]} 0 4
[junit4:junit4] 2> 1444787 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[26 (1437305982912823296)]} 0 1
[junit4:junit4] 2> 1444793 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[26 (1437305982915969024)]} 0 1
[junit4:junit4] 2> 1444793 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[26 (1437305982915969024)]} 0 4
[junit4:junit4] 2> 1444797 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[27 (1437305982923309056)]} 0 1
[junit4:junit4] 2> 1444805 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[27 (1437305982928551936)]} 0 1
[junit4:junit4] 2> 1444805 T3082 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[27 (1437305982928551936)]} 0 4
[junit4:junit4] 2> 1444806 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[27]} 0 7
[junit4:junit4] 2> 1444810 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[28 (1437305982936940544)]} 0 1
[junit4:junit4] 2> 1444819 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[28 (1437305982943232000)]} 0 1
[junit4:junit4] 2> 1444820 T3082 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[28 (1437305982943232000)]} 0 5
[junit4:junit4] 2> 1444820 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[28]} 0 8
[junit4:junit4] 2> 1444824 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[29 (1437305982951620608)]} 0 1
[junit4:junit4] 2> 1444830 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[29 (1437305982954766336)]} 0 1
[junit4:junit4] 2> 1444830 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[29 (1437305982954766336)]} 0 4
[junit4:junit4] 2> 1444833 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[30 (1437305982962106368)]} 0 0
[junit4:junit4] 2> 1444843 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[30 (1437305982968397824)]} 0 1
[junit4:junit4] 2> 1444844 T3100 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[30 (1437305982968397824)]} 0 5
[junit4:junit4] 2> 1444845 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[30]} 0 9
[junit4:junit4] 2> 1444848 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[31 (1437305982976786432)]} 0 1
[junit4:junit4] 2> 1444857 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[31 (1437305982983077888)]} 0 1
[junit4:junit4] 2> 1444857 T3100 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[31 (1437305982983077888)]} 0 4
[junit4:junit4] 2> 1444858 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[31]} 0 7
[junit4:junit4] 2> 1444862 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[32 (1437305982991466496)]} 0 1
[junit4:junit4] 2> 1444872 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[32 (1437305982998806528)]} 0 1
[junit4:junit4] 2> 1444872 T3082 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[32 (1437305982998806528)]} 0 4
[junit4:junit4] 2> 1444873 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[32]} 0 8
[junit4:junit4] 2> 1444876 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[33 (1437305983007195136)]} 0 0
[junit4:junit4] 2> 1444883 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[33 (1437305983010340864)]} 0 0
[junit4:junit4] 2> 1444883 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[33 (1437305983010340864)]} 0 4
[junit4:junit4] 2> 1444887 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[34 (1437305983017680896)]} 0 1
[junit4:junit4] 2> 1444896 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[34 (1437305983023972352)]} 0 1
[junit4:junit4] 2> 1444896 T3082 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[34 (1437305983023972352)]} 0 4
[junit4:junit4] 2> 1444897 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[34]} 0 8
[junit4:junit4] 2> 1444900 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[35 (1437305983032360960)]} 0 0
[junit4:junit4] 2> 1444909 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[35 (1437305983038652416)]} 0 0
[junit4:junit4] 2> 1444910 T3082 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[35 (1437305983038652416)]} 0 4
[junit4:junit4] 2> 1444911 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[35]} 0 8
[junit4:junit4] 2> 1444914 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[36 (1437305983045992448)]} 0 1
[junit4:junit4] 2> 1444920 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[36 (1437305983050186752)]} 0 0
[junit4:junit4] 2> 1444921 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[36 (1437305983050186752)]} 0 4
[junit4:junit4] 2> 1444924 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[37 (1437305983057526784)]} 0 0
[junit4:junit4] 2> 1444931 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[37 (1437305983060672512)]} 0 1
[junit4:junit4] 2> 1444931 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[37 (1437305983060672512)]} 0 4
[junit4:junit4] 2> 1444934 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[38 (1437305983068012544)]} 0 0
[junit4:junit4] 2> 1444941 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[38 (1437305983071158272)]} 0 1
[junit4:junit4] 2> 1444941 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[38 (1437305983071158272)]} 0 4
[junit4:junit4] 2> 1444945 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[39 (1437305983078498304)]} 0 1
[junit4:junit4] 2> 1444952 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[39 (1437305983082692608)]} 0 1
[junit4:junit4] 2> 1444952 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[39 (1437305983082692608)]} 0 4
[junit4:junit4] 2> 1444956 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[40 (1437305983090032640)]} 0 1
[junit4:junit4] 2> 1444965 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[40 (1437305983096324096)]} 0 1
[junit4:junit4] 2> 1444965 T3082 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[40 (1437305983096324096)]} 0 4
[junit4:junit4] 2> 1444966 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[40]} 0 8
[junit4:junit4] 2> 1444970 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[41 (1437305983104712704)]} 0 1
[junit4:junit4] 2> 1444978 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[41 (1437305983109955584)]} 0 1
[junit4:junit4] 2> 1444979 T3082 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[41 (1437305983109955584)]} 0 5
[junit4:junit4] 2> 1444979 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[41]} 0 7
[junit4:junit4] 2> 1444983 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[42 (1437305983118344192)]} 0 0
[junit4:junit4] 2> 1444989 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[42 (1437305983121489920)]} 0 1
[junit4:junit4] 2> 1444990 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[42 (1437305983121489920)]} 0 5
[junit4:junit4] 2> 1444994 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[43 (1437305983129878528)]} 0 1
[junit4:junit4] 2> 1445004 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[43 (1437305983137218560)]} 0 1
[junit4:junit4] 2> 1445005 T3082 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[43 (1437305983137218560)]} 0 5
[junit4:junit4] 2> 1445005 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[43]} 0 8
[junit4:junit4] 2> 1445009 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[44 (1437305983145607168)]} 0 1
[junit4:junit4] 2> 1445019 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[44 (1437305983152947200)]} 0 1
[junit4:junit4] 2> 1445020 T3082 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[44 (1437305983152947200)]} 0 5
[junit4:junit4] 2> 1445020 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[44]} 0 8
[junit4:junit4] 2> 1445024 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[45 (1437305983161335808)]} 0 1
[junit4:junit4] 2> 1445034 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[45 (1437305983168675840)]} 0 1
[junit4:junit4] 2> 1445035 T3100 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[45 (1437305983168675840)]} 0 5
[junit4:junit4] 2> 1445036 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[45]} 0 9
[junit4:junit4] 2> 1445039 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[46 (1437305983177064448)]} 0 1
[junit4:junit4] 2> 1445046 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[46 (1437305983181258752)]} 0 1
[junit4:junit4] 2> 1445046 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[46 (1437305983181258752)]} 0 4
[junit4:junit4] 2> 1445050 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[47 (1437305983188598784)]} 0 1
[junit4:junit4] 2> 1445057 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[47 (1437305983192793088)]} 0 1
[junit4:junit4] 2> 1445057 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[47 (1437305983192793088)]} 0 4
[junit4:junit4] 2> 1445061 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[48 (1437305983200133120)]} 0 1
[junit4:junit4] 2> 1445067 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[48 (1437305983204327424)]} 0 0
[junit4:junit4] 2> 1445068 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[48 (1437305983204327424)]} 0 4
[junit4:junit4] 2> 1445072 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[49 (1437305983211667456)]} 0 1
[junit4:junit4] 2> 1445078 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[49 (1437305983214813184)]} 0 1
[junit4:junit4] 2> 1445078 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[49 (1437305983214813184)]} 0 4
[junit4:junit4] 2> 1445081 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[50 (1437305983222153216)]} 0 0
[junit4:junit4] 2> 1445091 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[50 (1437305983228444672)]} 0 1
[junit4:junit4] 2> 1445091 T3082 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[50 (1437305983228444672)]} 0 4
[junit4:junit4] 2> 1445092 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[50]} 0 8
[junit4:junit4] 2> 1445096 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[51 (1437305983236833280)]} 0 1
[junit4:junit4] 2> 1445103 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[51 (1437305983241027584)]} 0 1
[junit4:junit4] 2> 1445103 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[51 (1437305983241027584)]} 0 4
[junit4:junit4] 2> 1445107 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[52 (1437305983248367616)]} 0 1
[junit4:junit4] 2> 1445114 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[52 (1437305983253610496)]} 0 0
[junit4:junit4] 2> 1445115 T3082 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[52 (1437305983253610496)]} 0 4
[junit4:junit4] 2> 1445116 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[52]} 0 7
[junit4:junit4] 2> 1445120 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[53 (1437305983261999104)]} 0 1
[junit4:junit4] 2> 1445129 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[53 (1437305983268290560)]} 0 1
[junit4:junit4] 2> 1445129 T3100 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[53 (1437305983268290560)]} 0 4
[junit4:junit4] 2> 1445130 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[53]} 0 8
[junit4:junit4] 2> 1445133 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[54 (1437305983276679168)]} 0 0
[junit4:junit4] 2> 1445142 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[54 (1437305983281922048)]} 0 1
[junit4:junit4] 2> 1445142 T3082 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[54 (1437305983281922048)]} 0 4
[junit4:junit4] 2> 1445143 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[54]} 0 7
[junit4:junit4] 2> 1445147 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[55 (1437305983290310656)]} 0 1
[junit4:junit4] 2> 1445154 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[55 (1437305983294504960)]} 0 1
[junit4:junit4] 2> 1445154 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[55 (1437305983294504960)]} 0 4
[junit4:junit4] 2> 1445158 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[56 (1437305983301844992)]} 0 1
[junit4:junit4] 2> 1445166 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[56 (1437305983308136448)]} 0 0
[junit4:junit4] 2> 1445167 T3100 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[56 (1437305983308136448)]} 0 4
[junit4:junit4] 2> 1445168 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[56]} 0 8
[junit4:junit4] 2> 1445172 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[57 (1437305983316525056)]} 0 1
[junit4:junit4] 2> 1445179 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[57 (1437305983320719360)]} 0 1
[junit4:junit4] 2> 1445179 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[57 (1437305983320719360)]} 0 4
[junit4:junit4] 2> 1445183 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[58 (1437305983328059392)]} 0 1
[junit4:junit4] 2> 1445190 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[58 (1437305983332253696)]} 0 1
[junit4:junit4] 2> 1445191 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[58 (1437305983332253696)]} 0 5
[junit4:junit4] 2> 1445194 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[59 (1437305983339593728)]} 0 1
[junit4:junit4] 2> 1445200 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[59 (1437305983342739456)]} 0 1
[junit4:junit4] 2> 1445200 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[59 (1437305983342739456)]} 0 4
[junit4:junit4] 2> 1445204 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[60 (1437305983350079488)]} 0 1
[junit4:junit4] 2> 1445212 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[60 (1437305983355322368)]} 0 1
[junit4:junit4] 2> 1445213 T3100 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[60 (1437305983355322368)]} 0 5
[junit4:junit4] 2> 1445213 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[60]} 0 7
[junit4:junit4] 2> 1445216 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[61 (1437305983363710976)]} 0 0
[junit4:junit4] 2> 1445222 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[61 (1437305983366856704)]} 0 0
[junit4:junit4] 2> 1445223 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[61 (1437305983366856704)]} 0 4
[junit4:junit4] 2> 1445226 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[62 (1437305983374196736)]} 0 0
[junit4:junit4] 2> 1445234 T3127 C966 P43881 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[62 (1437305983379439616)]} 0 0
[junit4:junit4] 2> 1445235 T3100 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[62 (1437305983379439616)]} 0 4
[junit4:junit4] 2> 1445236 T3084 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[62]} 0 7
[junit4:junit4] 2> 1445238 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[63 (1437305983386779648)]} 0 0
[junit4:junit4] 2> 1445246 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[63 (1437305983392022528)]} 0 0
[junit4:junit4] 2> 1445247 T3082 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[63 (1437305983392022528)]} 0 4
[junit4:junit4] 2> 1445248 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[63]} 0 7
[junit4:junit4] 2> 1445252 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[64 (1437305983400411136)]} 0 1
[junit4:junit4] 2> 1445259 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[64 (1437305983405654016)]} 0 0
[junit4:junit4] 2> 1445260 T3082 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[64 (1437305983405654016)]} 0 4
[junit4:junit4] 2> 1445261 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[64]} 0 7
[junit4:junit4] 2> 1445263 T3058 C968 P42119 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[65 (1437305983412994048)]} 0 0
[junit4:junit4] 2> 1445271 T3112 C964 P53377 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42127/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[65 (1437305983418236928)]} 0 0
[junit4:junit4] 2> 1445272 T3082 C965 P42127 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:42134/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[65 (1437305983418236928)]} 0 4
[junit4:junit4] 2> 1445273 T3098 C967 P42134 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[65]} 0 7
[junit4:junit4] 2> 1445276 T3058 C968 P42119 oasu
[...truncated too long message...]
n Starting to work on the main queue
[junit4:junit4] 2> 1670163 T3046 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 43881
[junit4:junit4] 2> 1670163 T3046 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=148821529
[junit4:junit4] 2> 1671167 T3046 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1671167 T3046 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1671172 T3046 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@70b053f8
[junit4:junit4] 2> 1671173 T3046 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=4,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=717,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4:junit4] 2> 1671174 T3046 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 1671174 T3046 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 1671174 T3046 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 1671176 T3046 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 1671177 T3046 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 1671178 T3046 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty4/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty4/index;done=false>>]
[junit4:junit4] 2> 1671178 T3046 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty4/index
[junit4:junit4] 2> 1671178 T3046 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty4 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty4;done=false>>]
[junit4:junit4] 2> 1671179 T3046 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864/jetty4
[junit4:junit4] 2> 1671180 T3212 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89831622107070476-127.0.0.1:43881_-n_0000000004) am no longer a leader.
[junit4:junit4] 2> 1671181 T3137 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> 1671181 T3137 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 1671181 T3046 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 1671181 T3137 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 1671251 T3046 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 1671253 T3046 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:42113 42113
[junit4:junit4] 2> 1671445 T3046 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 42119
[junit4:junit4] 2> !!!! WARNING: best effort to remove /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370721772864 FAILED !!!!!
[junit4:junit4] 2> 1671446 T3046 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 1671447 T3046 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:42113 42113
[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=3AC8DEEB6F31307C -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_ES -Dtests.timezone=Atlantic/Madeira -Dtests.file.encoding=US-ASCII
[junit4:junit4] ERROR 255s J0 | ChaosMonkeyShardSplitTest.testDistribSearch <<<
[junit4:junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:42127 returned non ok status:500, message:Server Error
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([3AC8DEEB6F31307C:BB2E50F3186E5040]: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:679)
[junit4:junit4] 2> 1671465 T3046 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 254545 T3045 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
[junit4:junit4] 2> NOTE: test params are: codec=Lucene3x, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=es_ES, timezone=Atlantic/Madeira
[junit4:junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=2,free=199826848,total=325124096
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestExtendedDismaxParser, TestUniqueKeyFieldResource, OverseerTest, TestRemoteStreaming, SuggesterFSTTest, TestQueryUtils, ScriptEngineTest, TestRandomDVFaceting, FastVectorHighlighterTest, CacheHeaderTest, CoreAdminHandlerTest, QueryParsingTest, TestCharFilters, UnloadDistributedZkTest, WordBreakSolrSpellCheckerTest, SpatialFilterTest, SOLR749Test, ResourceLoaderTest, QueryElevationComponentTest, SolrCoreTest, RegexBoostProcessorTest, BadCopyFieldTest, PluginInfoTest, PreAnalyzedFieldTest, OverseerCollectionProcessorTest, TestCloudManagedSchema, TestStressRecovery, BasicFunctionalityTest, PeerSyncTest, TestMaxScoreQueryParser, TestDocSet, AnalysisAfterCoreReloadTest, SyncSliceTest, PolyFieldTest, TestSolrIndexConfig, TestQuerySenderListener, TestSearchPerf, TestSolrDeletionPolicy1, ResponseLogComponentTest, MBeansHandlerTest, LukeRequestHandlerTest, TestCloudManagedSchemaAddField, FieldMutatingUpdateProcessorTest, BinaryUpdateRequestHandlerTest, DateFieldTest, JsonLoaderTest, TestSchemaResource, TestLRUCache, TestSolrQueryParser, TestFaceting, TestFuzzyAnalyzedSuggestions, ZkCLITest, MoreLikeThisHandlerTest, SolrIndexSplitterTest, TestSolrCoreProperties, TestSolrDeletionPolicy2, CircularListTest, SearchHandlerTest, TestReversedWildcardFilterFactory, RAMDirectoryFactoryTest, TestPropInjectDefaults, LeaderElectionTest, TestPerFieldSimilarity, RecoveryZkTest, PreAnalyzedUpdateProcessorTest, ZkControllerTest, TestSweetSpotSimilarityFactory, SchemaVersionSpecificBehaviorTest, SolrInfoMBeanTest, TestCoreContainer, SpellingQueryConverterTest, ShardRoutingTest, TestBadConfig, LeaderElectionIntegrationTest, BasicZkTest, AutoCommitTest, TestRecovery, DistributedSpellCheckComponentTest, TestRealTimeGet, TestJoin, TestFunctionQuery, DirectUpdateHandlerTest, TestIndexSearcher, HighlighterTest, SoftAutoCommitTest, CurrencyFieldOpenExchangeTest, SolrRequestParserTest, SuggesterTSTTest, TestStressLucene, TestCSVLoader, NoCacheHeaderTest, TestPseudoReturnFields, QueryEqualityTest, SortByFunctionTest, DocValuesMultiTest, XsltUpdateRequestHandlerTest, DisMaxRequestHandlerTest, DirectSolrSpellCheckerTest, PrimitiveFieldTypeTest, TermsComponentTest, RequestHandlersTest, TestValueSourceCache, TermVectorComponentTest, FieldAnalysisRequestHandlerTest, IndexSchemaTest, UpdateRequestProcessorFactoryTest, UniqFieldsUpdateProcessorFactoryTest, CSVRequestHandlerTest, TestBinaryResponseWriter, AlternateDirectoryTest, SolrIndexConfigTest, SampleTest, TestConfig, DirectSolrConnectionTest, SynonymTokenizerTest, EchoParamsTest, TestIBSimilarityFactory, TestFastWriter, TestPluginEnable, OpenExchangeRatesOrgProviderTest, URLClassifyProcessorTest, DateMathParserTest, TestSystemIdResolver, TestSuggestSpellingConverter, TestSolrJ, TestDocumentBuilder, SliceStateTest, SystemInfoHandlerTest, UUIDFieldTest, SolrTestCaseJ4Test, ChaosMonkeyShardSplitTest]
[junit4:junit4] Completed on J0 in 255.33s, 1 test, 1 error <<< FAILURES!
[...truncated 59 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:391: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:371: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build.xml:181: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/common-build.xml:437: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:1243: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:887: There were test failures: 297 suites, 1246 tests, 1 error, 13 ignored (7 assumptions)
Total time: 49 minutes 36 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure