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/20 08:14:21 UTC
[JENKINS] Lucene-Solr-Tests-trunk-Java7 - Build # 4078 - Still
Failing
Build: https://builds.apache.org/job/Lucene-Solr-Tests-trunk-Java7/4078/
1 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeyShardSplitTest.testDistribSearch
Error Message:
Server at http://127.0.0.1:22961/o_bh/e 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:22961/o_bh/e returned non ok status:500, message:Server Error
at __randomizedtesting.SeedInfo.seed([BCC412BA92B002D4:3D229CA2E5EF62E8]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.cloud.ShardSplitTest.splitShard(ShardSplitTest.java:228)
at org.apache.solr.cloud.ChaosMonkeyShardSplitTest.doTest(ChaosMonkeyShardSplitTest.java:136)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:601)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:722)
Build Log:
[...truncated 10097 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.ChaosMonkeyShardSplitTest
[junit4:junit4] 2> 1697391 T3788 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /o_bh/e
[junit4:junit4] 2> 1697398 T3788 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./solrtest-ChaosMonkeyShardSplitTest-1371708601512
[junit4:junit4] 2> 1697400 T3788 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 1697401 T3789 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 1697502 T3788 oasc.ZkTestServer.run start zk server on port:34193
[junit4:junit4] 2> 1697503 T3788 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1697509 T3795 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@613ff06c name:ZooKeeperConnection Watcher:127.0.0.1:34193 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1697509 T3788 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1697510 T3788 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 1697516 T3788 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1697535 T3797 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@deabcb6 name:ZooKeeperConnection Watcher:127.0.0.1:34193/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1697536 T3788 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1697536 T3788 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 1697541 T3788 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 1697544 T3788 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 1697546 T3788 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 1697580 T3788 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 1697581 T3788 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 1697594 T3788 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 1697596 T3788 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 1697706 T3788 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 1697707 T3788 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 1697712 T3788 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 1697713 T3788 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 1697716 T3788 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 1697717 T3788 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 1697720 T3788 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 1697721 T3788 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 1697724 T3788 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 1697725 T3788 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 1697728 T3788 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 1697729 T3788 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 1697732 T3788 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 1697733 T3788 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 1698030 T3788 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1698037 T3788 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:25871
[junit4:junit4] 2> 1698039 T3788 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1698039 T3788 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1698040 T3788 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1371708601855
[junit4:junit4] 2> 1698040 T3788 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1371708601855/solr.xml
[junit4:junit4] 2> 1698041 T3788 oasc.CoreContainer.<init> New CoreContainer 1170945131
[junit4:junit4] 2> 1698042 T3788 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1371708601855/'
[junit4:junit4] 2> 1698043 T3788 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1371708601855/'
[junit4:junit4] 2> 1698198 T3788 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1698199 T3788 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1698199 T3788 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1698200 T3788 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1698201 T3788 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1698201 T3788 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1698202 T3788 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1698202 T3788 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1698203 T3788 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1698204 T3788 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1698225 T3788 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1698226 T3788 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:34193/solr
[junit4:junit4] 2> 1698227 T3788 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1698228 T3788 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1698257 T3808 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1a666bba name:ZooKeeperConnection Watcher:127.0.0.1:34193 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1698258 T3788 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1698262 T3788 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1698276 T3788 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1698278 T3810 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@62e244c0 name:ZooKeeperConnection Watcher:127.0.0.1:34193/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1698279 T3788 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1698281 T3788 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 1698290 T3788 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 1698294 T3788 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 1698301 T3788 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:25871_o_bh%2Fe
[junit4:junit4] 2> 1698302 T3788 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:25871_o_bh%2Fe
[junit4:junit4] 2> 1698306 T3788 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 1698326 T3788 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 1698329 T3788 oasc.Overseer.start Overseer (id=89896294909280259-127.0.0.1:25871_o_bh%2Fe-n_0000000000) starting
[junit4:junit4] 2> 1698339 T3788 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 1698352 T3812 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 1698352 T3788 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 1698355 T3788 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 1698357 T3788 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1698360 T3811 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 1698365 T3813 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1698365 T3813 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1699863 T3811 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1699864 T3811 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:25871_o_bh%2Fe",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:25871/o_bh/e"}
[junit4:junit4] 2> 1699865 T3811 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 1699865 T3811 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 1699881 T3810 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> 1700369 T3813 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1371708601855/collection1
[junit4:junit4] 2> 1700369 T3813 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 1700370 T3813 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1700370 T3813 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 1700371 T3813 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1371708601855/collection1/'
[junit4:junit4] 2> 1700373 T3813 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1371708601855/collection1/lib/README' to classloader
[junit4:junit4] 2> 1700373 T3813 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1371708601855/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1700433 T3813 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 1700501 T3813 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1700603 T3813 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1700614 T3813 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 1701299 T3813 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1701304 T3813 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1701307 T3813 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1701312 T3813 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1701335 T3813 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1701336 T3813 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1371708601855/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/control/data/
[junit4:junit4] 2> 1701336 T3813 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@ed331b1
[junit4:junit4] 2> 1701337 T3813 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1701337 T3813 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/control/data
[junit4:junit4] 2> 1701338 T3813 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/control/data/index/
[junit4:junit4] 2> 1701338 T3813 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1701338 T3813 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/control/data/index
[junit4:junit4] 2> 1701342 T3813 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4fbfbee4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1f083e43),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1701342 T3813 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1701345 T3813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1701346 T3813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1701346 T3813 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1701347 T3813 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1701348 T3813 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1701348 T3813 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1701348 T3813 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1701349 T3813 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1701349 T3813 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1701362 T3813 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1701367 T3813 oass.SolrIndexSearcher.<init> Opening Searcher@60264925 main
[junit4:junit4] 2> 1701368 T3813 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/control/data/tlog
[junit4:junit4] 2> 1701369 T3813 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1701369 T3813 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1701373 T3814 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@60264925 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1701374 T3813 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1701374 T3813 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:25871/o_bh/e collection:control_collection shard:shard1
[junit4:junit4] 2> 1701375 T3813 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 1701392 T3813 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 1701394 T3813 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 1701395 T3813 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 1701395 T3813 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:25871/o_bh/e/collection1/
[junit4:junit4] 2> 1701395 T3813 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 1701395 T3813 oasc.SyncStrategy.syncToMe http://127.0.0.1:25871/o_bh/e/collection1/ has no replicas
[junit4:junit4] 2> 1701396 T3813 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:25871/o_bh/e/collection1/
[junit4:junit4] 2> 1701396 T3813 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 1702893 T3811 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1702922 T3810 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> 1702983 T3813 oasc.ZkController.register We are http://127.0.0.1:25871/o_bh/e/collection1/ and leader is http://127.0.0.1:25871/o_bh/e/collection1/
[junit4:junit4] 2> 1702983 T3813 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:25871/o_bh/e
[junit4:junit4] 2> 1702984 T3813 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 1702984 T3813 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 1702984 T3813 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1702987 T3813 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1702988 T3788 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
[junit4:junit4] 2> 1702989 T3788 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1702989 T3788 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1703002 T3788 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 1703004 T3788 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1703007 T3817 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@154e316c name:ZooKeeperConnection Watcher:127.0.0.1:34193/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1703007 T3788 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1703008 T3788 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1703010 T3788 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 1703199 T3788 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1703204 T3788 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:22961
[junit4:junit4] 2> 1703205 T3788 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1703206 T3788 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1703207 T3788 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1371708607122
[junit4:junit4] 2> 1703207 T3788 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1371708607122/solr.xml
[junit4:junit4] 2> 1703208 T3788 oasc.CoreContainer.<init> New CoreContainer 2061712758
[junit4:junit4] 2> 1703209 T3788 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1371708607122/'
[junit4:junit4] 2> 1703209 T3788 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1371708607122/'
[junit4:junit4] 2> 1703363 T3788 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1703364 T3788 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1703365 T3788 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1703366 T3788 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1703366 T3788 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1703367 T3788 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1703367 T3788 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1703368 T3788 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1703369 T3788 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1703369 T3788 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1703387 T3788 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1703388 T3788 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:34193/solr
[junit4:junit4] 2> 1703389 T3788 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1703390 T3788 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1703393 T3828 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@58361885 name:ZooKeeperConnection Watcher:127.0.0.1:34193 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1703394 T3788 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1703414 T3788 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1703423 T3788 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1703425 T3830 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@30efced0 name:ZooKeeperConnection Watcher:127.0.0.1:34193/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1703425 T3788 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1703435 T3788 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1704434 T3811 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1704435 T3811 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:25871_o_bh%2Fe",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:25871/o_bh/e"}
[junit4:junit4] 2> 1704463 T3788 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:22961_o_bh%2Fe
[junit4:junit4] 2> 1704482 T3788 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:22961_o_bh%2Fe
[junit4:junit4] 2> 1704483 T3810 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> 1704483 T3817 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> 1704483 T3830 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> 1704491 T3817 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 1704491 T3830 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 1704498 T3810 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 1704499 T3810 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> 1704504 T3831 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1704505 T3831 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1705992 T3811 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1705993 T3811 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[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:22961_o_bh%2Fe",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:22961/o_bh/e"}
[junit4:junit4] 2> 1705993 T3811 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 1705993 T3811 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 1706008 T3817 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> 1706008 T3830 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> 1706008 T3810 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> 1706508 T3831 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1371708607122/collection1
[junit4:junit4] 2> 1706508 T3831 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 1706509 T3831 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1706509 T3831 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 1706510 T3831 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1371708607122/collection1/'
[junit4:junit4] 2> 1706511 T3831 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1371708607122/collection1/lib/README' to classloader
[junit4:junit4] 2> 1706512 T3831 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1371708607122/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1706553 T3831 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 1706598 T3831 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1706699 T3831 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1706709 T3831 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 1707307 T3831 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1707312 T3831 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1707315 T3831 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1707321 T3831 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1707346 T3831 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1707347 T3831 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1371708607122/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty1/
[junit4:junit4] 2> 1707347 T3831 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@ed331b1
[junit4:junit4] 2> 1707348 T3831 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1707349 T3831 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty1
[junit4:junit4] 2> 1707349 T3831 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty1/index/
[junit4:junit4] 2> 1707349 T3831 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1707350 T3831 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty1/index
[junit4:junit4] 2> 1707354 T3831 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3a644592 lockFactory=org.apache.lucene.store.NativeFSLockFactory@53a0f25),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1707355 T3831 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1707359 T3831 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1707360 T3831 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1707361 T3831 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1707362 T3831 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1707363 T3831 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1707363 T3831 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1707363 T3831 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1707364 T3831 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1707365 T3831 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1707386 T3831 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1707394 T3831 oass.SolrIndexSearcher.<init> Opening Searcher@6ba0a2f1 main
[junit4:junit4] 2> 1707395 T3831 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty1/tlog
[junit4:junit4] 2> 1707396 T3831 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1707396 T3831 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1707403 T3832 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6ba0a2f1 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1707407 T3831 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1707407 T3831 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:22961/o_bh/e collection:collection1 shard:shard1
[junit4:junit4] 2> 1707408 T3831 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 1707519 T3831 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 1707539 T3831 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 1707540 T3831 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 1707540 T3831 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:22961/o_bh/e/collection1/
[junit4:junit4] 2> 1707541 T3831 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 1707541 T3831 oasc.SyncStrategy.syncToMe http://127.0.0.1:22961/o_bh/e/collection1/ has no replicas
[junit4:junit4] 2> 1707541 T3831 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:22961/o_bh/e/collection1/
[junit4:junit4] 2> 1707542 T3831 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 1709020 T3811 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1709041 T3810 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> 1709041 T3817 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> 1709042 T3830 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> 1709074 T3831 oasc.ZkController.register We are http://127.0.0.1:22961/o_bh/e/collection1/ and leader is http://127.0.0.1:22961/o_bh/e/collection1/
[junit4:junit4] 2> 1709074 T3831 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:22961/o_bh/e
[junit4:junit4] 2> 1709075 T3831 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 1709075 T3831 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 1709075 T3831 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1709077 T3831 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1709079 T3788 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
[junit4:junit4] 2> 1709080 T3788 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1709080 T3788 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1709398 T3788 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1709417 T3788 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:35206
[junit4:junit4] 2> 1709418 T3788 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1709419 T3788 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1709419 T3788 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1371708613211
[junit4:junit4] 2> 1709420 T3788 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1371708613211/solr.xml
[junit4:junit4] 2> 1709421 T3788 oasc.CoreContainer.<init> New CoreContainer 916089800
[junit4:junit4] 2> 1709421 T3788 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1371708613211/'
[junit4:junit4] 2> 1709422 T3788 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1371708613211/'
[junit4:junit4] 2> 1709567 T3788 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1709568 T3788 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1709569 T3788 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1709569 T3788 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1709570 T3788 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1709570 T3788 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1709571 T3788 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1709572 T3788 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1709572 T3788 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1709573 T3788 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1709590 T3788 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1709591 T3788 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:34193/solr
[junit4:junit4] 2> 1709592 T3788 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1709593 T3788 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1709597 T3844 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2f17bb5e name:ZooKeeperConnection Watcher:127.0.0.1:34193 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1709597 T3788 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1709616 T3788 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1709625 T3788 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1709627 T3846 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@377a75c2 name:ZooKeeperConnection Watcher:127.0.0.1:34193/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1709628 T3788 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1709637 T3788 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1710545 T3811 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1710546 T3811 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[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:22961_o_bh%2Fe",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:22961/o_bh/e"}
[junit4:junit4] 2> 1710563 T3817 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> 1710564 T3830 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> 1710563 T3846 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> 1710563 T3810 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> 1710641 T3788 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:35206_o_bh%2Fe
[junit4:junit4] 2> 1710644 T3788 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:35206_o_bh%2Fe
[junit4:junit4] 2> 1710646 T3846 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> 1710646 T3830 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 1710647 T3810 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 1710646 T3817 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 1710647 T3810 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> 1710647 T3830 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> 1710647 T3817 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> 1710654 T3846 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 1710660 T3847 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1710660 T3847 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1712068 T3811 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1712069 T3811 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[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:35206_o_bh%2Fe",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:35206/o_bh/e"}
[junit4:junit4] 2> 1712069 T3811 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 1712069 T3811 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 1712085 T3810 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> 1712085 T3846 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> 1712085 T3830 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> 1712085 T3817 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> 1712664 T3847 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1371708613211/collection1
[junit4:junit4] 2> 1712664 T3847 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 1712665 T3847 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1712665 T3847 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 1712667 T3847 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1371708613211/collection1/'
[junit4:junit4] 2> 1712668 T3847 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1371708613211/collection1/lib/README' to classloader
[junit4:junit4] 2> 1712668 T3847 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1371708613211/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1712709 T3847 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 1712754 T3847 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1712856 T3847 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1712865 T3847 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 1713458 T3847 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1713462 T3847 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1713465 T3847 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1713470 T3847 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1713491 T3847 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1713491 T3847 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1371708613211/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty2/
[junit4:junit4] 2> 1713492 T3847 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@ed331b1
[junit4:junit4] 2> 1713493 T3847 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1713493 T3847 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty2
[junit4:junit4] 2> 1713494 T3847 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty2/index/
[junit4:junit4] 2> 1713494 T3847 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1713494 T3847 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty2/index
[junit4:junit4] 2> 1713498 T3847 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3673a01 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16c22487),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1713499 T3847 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1713503 T3847 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1713503 T3847 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1713504 T3847 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1713505 T3847 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1713506 T3847 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1713506 T3847 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1713506 T3847 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1713507 T3847 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1713508 T3847 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1713525 T3847 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1713533 T3847 oass.SolrIndexSearcher.<init> Opening Searcher@42318d6b main
[junit4:junit4] 2> 1713533 T3847 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty2/tlog
[junit4:junit4] 2> 1713535 T3847 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1713535 T3847 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1713541 T3848 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@42318d6b main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1713544 T3847 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1713545 T3847 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:35206/o_bh/e collection:collection1 shard:shard2
[junit4:junit4] 2> 1713546 T3847 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 1713591 T3847 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 1713600 T3847 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 1713600 T3847 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 1713601 T3847 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:35206/o_bh/e/collection1/
[junit4:junit4] 2> 1713601 T3847 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 1713601 T3847 oasc.SyncStrategy.syncToMe http://127.0.0.1:35206/o_bh/e/collection1/ has no replicas
[junit4:junit4] 2> 1713601 T3847 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:35206/o_bh/e/collection1/
[junit4:junit4] 2> 1713602 T3847 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 1715092 T3811 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1715110 T3810 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> 1715110 T3830 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> 1715110 T3846 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> 1715110 T3817 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> 1715142 T3847 oasc.ZkController.register We are http://127.0.0.1:35206/o_bh/e/collection1/ and leader is http://127.0.0.1:35206/o_bh/e/collection1/
[junit4:junit4] 2> 1715142 T3847 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:35206/o_bh/e
[junit4:junit4] 2> 1715142 T3847 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 1715143 T3847 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 1715143 T3847 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1715145 T3847 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1715147 T3788 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
[junit4:junit4] 2> 1715148 T3788 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1715149 T3788 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1715452 T3788 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1715457 T3788 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:26175
[junit4:junit4] 2> 1715458 T3788 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1715458 T3788 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1715459 T3788 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1371708619281
[junit4:junit4] 2> 1715460 T3788 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1371708619281/solr.xml
[junit4:junit4] 2> 1715460 T3788 oasc.CoreContainer.<init> New CoreContainer 1856980664
[junit4:junit4] 2> 1715461 T3788 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1371708619281/'
[junit4:junit4] 2> 1715462 T3788 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1371708619281/'
[junit4:junit4] 2> 1715636 T3788 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1715637 T3788 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1715638 T3788 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1715639 T3788 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1715639 T3788 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1715640 T3788 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1715640 T3788 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1715641 T3788 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1715642 T3788 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1715642 T3788 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1715661 T3788 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1715663 T3788 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:34193/solr
[junit4:junit4] 2> 1715663 T3788 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1715664 T3788 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1715668 T3860 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5f10726b name:ZooKeeperConnection Watcher:127.0.0.1:34193 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1715669 T3788 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1715683 T3788 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1715691 T3788 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1715694 T3862 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2a5a8b7d name:ZooKeeperConnection Watcher:127.0.0.1:34193/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1715694 T3788 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1715706 T3788 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1716623 T3811 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1716624 T3811 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[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:35206_o_bh%2Fe",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:35206/o_bh/e"}
[junit4:junit4] 2> 1716640 T3830 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> 1716640 T3810 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> 1716640 T3862 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> 1716640 T3817 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> 1716640 T3846 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> 1716709 T3788 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:26175_o_bh%2Fe
[junit4:junit4] 2> 1716712 T3788 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:26175_o_bh%2Fe
[junit4:junit4] 2> 1716715 T3846 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> 1716715 T3810 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1716715 T3817 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1716715 T3862 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1716715 T3830 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1716716 T3862 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> 1716716 T3817 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> 1716715 T3810 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> 1716716 T3830 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> 1716723 T3846 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1716730 T3863 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1716731 T3863 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1718144 T3811 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1718145 T3811 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"4",
[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:26175_o_bh%2Fe",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:26175/o_bh/e"}
[junit4:junit4] 2> 1718145 T3811 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 1718146 T3811 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 1718161 T3817 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> 1718161 T3846 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> 1718161 T3862 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> 1718161 T3830 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> 1718161 T3810 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> 1718735 T3863 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1371708619281/collection1
[junit4:junit4] 2> 1718735 T3863 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 1718736 T3863 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1718736 T3863 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 1718738 T3863 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1371708619281/collection1/'
[junit4:junit4] 2> 1718740 T3863 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1371708619281/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1718741 T3863 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1371708619281/collection1/lib/README' to classloader
[junit4:junit4] 2> 1718799 T3863 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 1718863 T3863 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1718964 T3863 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1718973 T3863 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 1719560 T3863 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1719564 T3863 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1719567 T3863 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1719573 T3863 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1719604 T3863 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1719605 T3863 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1371708619281/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty3/
[junit4:junit4] 2> 1719605 T3863 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@ed331b1
[junit4:junit4] 2> 1719606 T3863 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1719607 T3863 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty3
[junit4:junit4] 2> 1719607 T3863 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty3/index/
[junit4:junit4] 2> 1719608 T3863 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1719608 T3863 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty3/index
[junit4:junit4] 2> 1719612 T3863 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@165324f3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@63e0fab5),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1719612 T3863 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1719617 T3863 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1719617 T3863 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1719618 T3863 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1719619 T3863 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1719620 T3863 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1719620 T3863 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1719621 T3863 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1719622 T3863 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1719622 T3863 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1719639 T3863 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1719648 T3863 oass.SolrIndexSearcher.<init> Opening Searcher@153d3def main
[junit4:junit4] 2> 1719648 T3863 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty3/tlog
[junit4:junit4] 2> 1719650 T3863 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1719650 T3863 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1719658 T3864 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@153d3def main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1719661 T3863 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1719662 T3863 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:26175/o_bh/e collection:collection1 shard:shard1
[junit4:junit4] 2> 1719665 T3863 oasc.ZkController.register We are http://127.0.0.1:26175/o_bh/e/collection1/ and leader is http://127.0.0.1:22961/o_bh/e/collection1/
[junit4:junit4] 2> 1719666 T3863 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:26175/o_bh/e
[junit4:junit4] 2> 1719666 T3863 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 1719667 T3863 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C1421 name=collection1 org.apache.solr.core.SolrCore@2670bc41 url=http://127.0.0.1:26175/o_bh/e/collection1 node=127.0.0.1:26175_o_bh%2Fe C1421_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:26175_o_bh%2Fe, base_url=http://127.0.0.1:26175/o_bh/e}
[junit4:junit4] 2> 1719668 T3865 C1421 P26175 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 1719668 T3863 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1719669 T3865 C1421 P26175 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 1719670 T3865 C1421 P26175 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 1719671 T3865 C1421 P26175 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1719671 T3788 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
[junit4:junit4] 2> 1719672 T3788 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1719672 T3865 C1421 P26175 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1719672 T3788 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1719697 T3820 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 4, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 1719702 T3811 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1719703 T3811 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"4",
[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:26175_o_bh%2Fe",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:26175/o_bh/e"}
[junit4:junit4] 2> 1719717 T3846 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> 1719717 T3810 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> 1719717 T3817 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> 1719717 T3862 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> 1719717 T3830 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> 1719928 T3788 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1719933 T3788 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:45459
[junit4:junit4] 2> 1719934 T3788 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1719935 T3788 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1719935 T3788 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1371708623807
[junit4:junit4] 2> 1719936 T3788 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1371708623807/solr.xml
[junit4:junit4] 2> 1719937 T3788 oasc.CoreContainer.<init> New CoreContainer 274369780
[junit4:junit4] 2> 1719937 T3788 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1371708623807/'
[junit4:junit4] 2> 1719938 T3788 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1371708623807/'
[junit4:junit4] 2> 1720044 T3788 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1720045 T3788 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1720045 T3788 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1720046 T3788 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1720046 T3788 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1720047 T3788 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1720047 T3788 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1720047 T3788 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1720048 T3788 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1720048 T3788 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1720061 T3788 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1720062 T3788 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:34193/solr
[junit4:junit4] 2> 1720062 T3788 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1720063 T3788 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1720067 T3877 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2e648e8c name:ZooKeeperConnection Watcher:127.0.0.1:34193 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1720068 T3788 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1720083 T3788 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1720093 T3788 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1720095 T3879 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5e2a7248 name:ZooKeeperConnection Watcher:127.0.0.1:34193/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1720096 T3788 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1720104 T3788 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1720699 T3820 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 4, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 1720699 T3820 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=4&state=recovering&nodeName=127.0.0.1:26175_o_bh%252Fe&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1002
[junit4:junit4] 2> 1721107 T3788 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:45459_o_bh%2Fe
[junit4:junit4] 2> 1721110 T3788 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:45459_o_bh%2Fe
[junit4:junit4] 2> 1721112 T3846 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> 1721113 T3810 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1721113 T3879 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1721113 T3862 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1721113 T3830 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1721114 T3846 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1721113 T3817 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1721114 T3830 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> 1721114 T3862 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> 1721113 T3810 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> 1721115 T3817 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> 1721134 T3880 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1721134 T3880 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1721221 T3811 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1721222 T3811 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"5",
[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:45459_o_bh%2Fe",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:45459/o_bh/e"}
[junit4:junit4] 2> 1721223 T3811 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 1721223 T3811 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 1721236 T3846 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> 1721236 T3830 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> 1721236 T3817 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> 1721236 T3879 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> 1721236 T3810 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> 1721236 T3862 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> 1722137 T3880 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1371708623807/collection1
[junit4:junit4] 2> 1722137 T3880 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 1722138 T3880 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1722138 T3880 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 1722140 T3880 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1371708623807/collection1/'
[junit4:junit4] 2> 1722142 T3880 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1371708623807/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1722142 T3880 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1371708623807/collection1/lib/README' to classloader
[junit4:junit4] 2> 1722204 T3880 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_50
[junit4:junit4] 2> 1722277 T3880 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1722378 T3880 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1722384 T3880 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> ASYNC NEW_CORE C1422 name=collection1 org.apache.solr.core.SolrCore@2670bc41 url=http://127.0.0.1:26175/o_bh/e/collection1 node=127.0.0.1:26175_o_bh%2Fe C1422_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:26175_o_bh%2Fe, base_url=http://127.0.0.1:26175/o_bh/e}
[junit4:junit4] 2> 1722701 T3865 C1422 P26175 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:22961/o_bh/e/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 1722701 T3865 C1422 P26175 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:26175/o_bh/e START replicas=[http://127.0.0.1:22961/o_bh/e/collection1/] nUpdates=100
[junit4:junit4] 2> 1722702 T3865 C1422 P26175 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 1722702 T3865 C1422 P26175 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 1722702 T3865 C1422 P26175 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 1722702 T3865 C1422 P26175 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 1722702 T3865 C1422 P26175 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 1722703 T3865 C1422 P26175 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:22961/o_bh/e/collection1/. core=collection1
[junit4:junit4] 2> 1722703 T3865 C1422 P26175 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C1423 name=collection1 org.apache.solr.core.SolrCore@2d1897fb url=http://127.0.0.1:22961/o_bh/e/collection1 node=127.0.0.1:22961_o_bh%2Fe C1423_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:22961_o_bh%2Fe, base_url=http://127.0.0.1:22961/o_bh/e, leader=true}
[junit4:junit4] 2> 1722710 T3821 C1423 P22961 oasc.SolrCore.execute [collection1] webapp=/o_bh/e path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=2
[junit4:junit4] 2> 1722714 T3822 C1423 P22961 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1722718 T3822 C1423 P22961 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3a644592 lockFactory=org.apache.lucene.store.NativeFSLockFactory@53a0f25),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1722720 T3822 C1423 P22961 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1722721 T3822 C1423 P22961 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3a644592 lockFactory=org.apache.lucene.store.NativeFSLockFactory@53a0f25),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3a644592 lockFactory=org.apache.lucene.store.NativeFSLockFactory@53a0f25),segFN=segments_2,generation=2}
[junit4:junit4] 2> 1722721 T3822 C1423 P22961 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1722722 T3822 C1423 P22961 oass.SolrIndexSearcher.<init> Opening Searcher@4f33d784 realtime
[junit4:junit4] 2> 1722723 T3822 C1423 P22961 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1722723 T3822 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e 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> 1722724 T3865 C1422 P26175 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 1722725 T3865 C1422 P26175 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 1722727 T3823 C1423 P22961 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 1722728 T3823 C1423 P22961 oasc.SolrCore.execute [collection1] webapp=/o_bh/e path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=2
[junit4:junit4] 2> 1722729 T3865 C1422 P26175 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 1722729 T3865 C1422 P26175 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 1722729 T3865 C1422 P26175 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 1722732 T3823 C1423 P22961 oasc.SolrCore.execute [collection1] webapp=/o_bh/e path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=0
[junit4:junit4] 2> 1722733 T3865 C1422 P26175 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 1722734 T3865 C1422 P26175 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty3/index.20130620021026845
[junit4:junit4] 2> 1722735 T3865 C1422 P26175 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@5f3bf202 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7cd1982) fullCopy=false
[junit4:junit4] 2> 1722737 T3823 C1423 P22961 oasc.SolrCore.execute [collection1] webapp=/o_bh/e path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 1722739 T3865 C1422 P26175 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 1722740 T3865 C1422 P26175 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 1722741 T3865 C1422 P26175 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 1722743 T3865 C1422 P26175 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@165324f3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@63e0fab5),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@165324f3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@63e0fab5),segFN=segments_2,generation=2}
[junit4:junit4] 2> 1722744 T3865 C1422 P26175 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1722744 T3865 C1422 P26175 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 1722744 T3865 C1422 P26175 oass.SolrIndexSearcher.<init> Opening Searcher@22ffc604 main
[junit4:junit4] 2> 1722746 T3864 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@22ffc604 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1722746 T3865 C1422 P26175 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty3/index.20130620021026845 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty3/index.20130620021026845;done=true>>]
[junit4:junit4] 2> 1722747 T3865 C1422 P26175 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty3/index.20130620021026845
[junit4:junit4] 2> 1722747 T3865 C1422 P26175 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty3/index.20130620021026845
[junit4:junit4] 2> 1722747 T3865 C1422 P26175 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 1722748 T3865 C1422 P26175 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 1722748 T3865 C1422 P26175 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 1722748 T3865 C1422 P26175 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1722750 T3865 C1422 P26175 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 1722855 T3880 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1722858 T3880 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1722860 T3880 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1722865 T3880 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1722892 T3880 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1722892 T3880 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1371708623807/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty4/
[junit4:junit4] 2> 1722893 T3880 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@ed331b1
[junit4:junit4] 2> 1722893 T3880 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1722894 T3880 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty4
[junit4:junit4] 2> 1722894 T3880 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty4/index/
[junit4:junit4] 2> 1722894 T3880 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1722895 T3880 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty4/index
[junit4:junit4] 2> 1722898 T3880 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@49131556 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7b3409dc),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1722898 T3880 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1722901 T3880 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1722902 T3880 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1722902 T3880 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1722903 T3880 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1722903 T3880 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1722904 T3880 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1722905 T3880 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1722906 T3880 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1722906 T3880 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1722918 T3880 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1722926 T3880 oass.SolrIndexSearcher.<init> Opening Searcher@50f96063 main
[junit4:junit4] 2> 1722926 T3880 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty4/tlog
[junit4:junit4] 2> 1722927 T3880 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1722928 T3880 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1722931 T3883 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@50f96063 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1722933 T3880 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1722934 T3880 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:45459/o_bh/e collection:collection1 shard:shard2
[junit4:junit4] 2> 1722936 T3880 oasc.ZkController.register We are http://127.0.0.1:45459/o_bh/e/collection1/ and leader is http://127.0.0.1:35206/o_bh/e/collection1/
[junit4:junit4] 2> 1722937 T3880 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:45459/o_bh/e
[junit4:junit4] 2> 1722937 T3880 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 1722937 T3880 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C1424 name=collection1 org.apache.solr.core.SolrCore@3198de41 url=http://127.0.0.1:45459/o_bh/e/collection1 node=127.0.0.1:45459_o_bh%2Fe C1424_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:45459_o_bh%2Fe, base_url=http://127.0.0.1:45459/o_bh/e}
[junit4:junit4] 2> 1722937 T3884 C1424 P45459 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 1722938 T3880 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1722938 T3884 C1424 P45459 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 1722939 T3884 C1424 P45459 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 1722939 T3884 C1424 P45459 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1722939 T3788 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1
[junit4:junit4] 2> 1722940 T3788 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1722940 T3884 C1424 P45459 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1722941 T3788 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1722960 T3788 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1722960 T3836 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 1722961 T3788 oasc.AbstractFullDistribZkTestBase.waitForThingsToLevelOut Wait for recoveries to finish - wait 15 for each attempt
[junit4:junit4] 2> 1722962 T3788 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):15
[junit4:junit4] 2> 1722962 T3788 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1723964 T3788 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1724243 T3811 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1724244 T3811 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"4",
[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:26175_o_bh%2Fe",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:26175/o_bh/e"}
[junit4:junit4] 2> 1724277 T3811 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"5",
[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:45459_o_bh%2Fe",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:45459/o_bh/e"}
[junit4:junit4] 2> 1724355 T3862 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> 1724355 T3879 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> 1724355 T3830 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> 1724355 T3846 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> 1724355 T3810 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> 1724355 T3817 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> 1724963 T3836 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 1724964 T3836 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=5&state=recovering&nodeName=127.0.0.1:45459_o_bh%252Fe&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2004
[junit4:junit4] 2> 1724967 T3788 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1725970 T3788 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> C1424_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:45459_o_bh%2Fe, base_url=http://127.0.0.1:45459/o_bh/e}
[junit4:junit4] 2> 1726965 T3884 C1424 P45459 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:35206/o_bh/e/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 1726965 T3884 C1424 P45459 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:45459/o_bh/e START replicas=[http://127.0.0.1:35206/o_bh/e/collection1/] nUpdates=100
[junit4:junit4] 2> 1726966 T3884 C1424 P45459 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 1726966 T3884 C1424 P45459 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 1726966 T3884 C1424 P45459 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 1726966 T3884 C1424 P45459 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 1726966 T3884 C1424 P45459 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 1726967 T3884 C1424 P45459 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:35206/o_bh/e/collection1/. core=collection1
[junit4:junit4] 2> 1726967 T3884 C1424 P45459 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C1425 name=collection1 org.apache.solr.core.SolrCore@78585fbf url=http://127.0.0.1:35206/o_bh/e/collection1 node=127.0.0.1:35206_o_bh%2Fe C1425_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:35206_o_bh%2Fe, base_url=http://127.0.0.1:35206/o_bh/e, leader=true}
[junit4:junit4] 2> 1726973 T3837 C1425 P35206 oasc.SolrCore.execute [collection1] webapp=/o_bh/e path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 2> 1726974 T3788 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1726977 T3838 C1425 P35206 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1726980 T3838 C1425 P35206 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3673a01 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16c22487),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1726980 T3838 C1425 P35206 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1726981 T3838 C1425 P35206 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3673a01 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16c22487),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3673a01 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16c22487),segFN=segments_2,generation=2}
[junit4:junit4] 2> 1726981 T3838 C1425 P35206 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1726982 T3838 C1425 P35206 oass.SolrIndexSearcher.<init> Opening Searcher@293c15f5 realtime
[junit4:junit4] 2> 1726982 T3838 C1425 P35206 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1726982 T3838 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 5
[junit4:junit4] 2> 1726983 T3884 C1424 P45459 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 1726984 T3884 C1424 P45459 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 1726985 T3839 C1425 P35206 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 1726986 T3839 C1425 P35206 oasc.SolrCore.execute [collection1] webapp=/o_bh/e path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> 1726986 T3884 C1424 P45459 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 1726987 T3884 C1424 P45459 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 1726987 T3884 C1424 P45459 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 1726989 T3839 C1425 P35206 oasc.SolrCore.execute [collection1] webapp=/o_bh/e path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=0
[junit4:junit4] 2> 1726990 T3884 C1424 P45459 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 1726991 T3884 C1424 P45459 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty4/index.20130620021031102
[junit4:junit4] 2> 1726991 T3884 C1424 P45459 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@4c9a081c lockFactory=org.apache.lucene.store.NativeFSLockFactory@71e92179) fullCopy=false
[junit4:junit4] 2> 1726994 T3839 C1425 P35206 oasc.SolrCore.execute [collection1] webapp=/o_bh/e path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 1726995 T3884 C1424 P45459 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 1726996 T3884 C1424 P45459 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 1726996 T3884 C1424 P45459 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 1726998 T3884 C1424 P45459 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@49131556 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7b3409dc),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@49131556 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7b3409dc),segFN=segments_2,generation=2}
[junit4:junit4] 2> 1726998 T3884 C1424 P45459 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1726998 T3884 C1424 P45459 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 1726999 T3884 C1424 P45459 oass.SolrIndexSearcher.<init> Opening Searcher@2e709c0c main
[junit4:junit4] 2> 1727000 T3883 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2e709c0c main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1727000 T3884 C1424 P45459 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty4/index.20130620021031102 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty4/index.20130620021031102;done=true>>]
[junit4:junit4] 2> 1727000 T3884 C1424 P45459 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty4/index.20130620021031102
[junit4:junit4] 2> 1727001 T3884 C1424 P45459 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty4/index.20130620021031102
[junit4:junit4] 2> 1727001 T3884 C1424 P45459 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 1727001 T3884 C1424 P45459 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 1727001 T3884 C1424 P45459 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 1727001 T3884 C1424 P45459 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1727003 T3884 C1424 P45459 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 1727366 T3811 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1727367 T3811 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"5",
[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:45459_o_bh%2Fe",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:45459/o_bh/e"}
[junit4:junit4] 2> 1727428 T3862 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> 1727428 T3879 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> 1727428 T3817 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> 1727428 T3830 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> 1727428 T3810 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> 1727428 T3846 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> 1727976 T3788 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1727978 T3788 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: collection1
[junit4:junit4] 2> ASYNC NEW_CORE C1426 name=collection1 org.apache.solr.core.SolrCore@1ca6ebb9 url=http://127.0.0.1:25871/o_bh/e/collection1 node=127.0.0.1:25871_o_bh%2Fe C1426_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:25871_o_bh%2Fe, base_url=http://127.0.0.1:25871/o_bh/e, leader=true}
[junit4:junit4] 2> 1727987 T3800 C1426 P25871 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1727993 T3800 C1426 P25871 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4fbfbee4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1f083e43),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1727994 T3800 C1426 P25871 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1727995 T3800 C1426 P25871 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4fbfbee4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1f083e43),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@4fbfbee4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@1f083e43),segFN=segments_2,generation=2}
[junit4:junit4] 2> 1727996 T3800 C1426 P25871 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1727997 T3800 C1426 P25871 oass.SolrIndexSearcher.<init> Opening Searcher@1f813456 main
[junit4:junit4] 2> 1727997 T3800 C1426 P25871 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1727998 T3814 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1f813456 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1727999 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 12
[junit4:junit4] 2> C1424_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:45459_o_bh%2Fe, base_url=http://127.0.0.1:45459/o_bh/e}
[junit4:junit4] 2> 1728021 T3869 C1424 P45459 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:22961/o_bh/e/collection1/, StdNode: http://127.0.0.1:26175/o_bh/e/collection1/, StdNode: http://127.0.0.1:35206/o_bh/e/collection1/, StdNode: http://127.0.0.1:45459/o_bh/e/collection1/] params:commit_end_point=true&commit=true&softCommit=false&waitSearcher=true&expungeDeletes=false
[junit4:junit4] 2> 1728026 T3840 C1425 P35206 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1728026 T3824 C1423 P22961 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1728026 T3870 C1424 P45459 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1728030 T3824 C1423 P22961 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3a644592 lockFactory=org.apache.lucene.store.NativeFSLockFactory@53a0f25),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3a644592 lockFactory=org.apache.lucene.store.NativeFSLockFactory@53a0f25),segFN=segments_3,generation=3}
[junit4:junit4] 2> 1728028 T3840 C1425 P35206 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3673a01 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16c22487),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3673a01 lockFactory=org.apache.lucene.store.NativeFSLockFactory@16c22487),segFN=segments_3,generation=3}
[junit4:junit4] 2> 1728032 T3824 C1423 P22961 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 1728031 T3870 C1424 P45459 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@49131556 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7b3409dc),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@49131556 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7b3409dc),segFN=segments_3,generation=3}
[junit4:junit4] 2> 1728035 T3824 C1423 P22961 oass.SolrIndexSearcher.<init> Opening Searcher@2bf5d50e main
[junit4:junit4] 2> 1728034 T3840 C1425 P35206 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 1728036 T3824 C1423 P22961 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1728035 T3870 C1424 P45459 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 1728037 T3832 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2bf5d50e main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1728037 T3840 C1425 P35206 oass.SolrIndexSearcher.<init> Opening Searcher@142f0c0e main
[junit4:junit4] 2> 1728039 T3824 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 13
[junit4:junit4] 2> 1728038 T3870 C1424 P45459 oass.SolrIndexSearcher.<init> Opening Searcher@253cdf6d main
[junit4:junit4] 2> C1422_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:26175_o_bh%2Fe, base_url=http://127.0.0.1:26175/o_bh/e}
[junit4:junit4] 2> 1728038 T3852 C1422 P26175 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1728040 T3870 C1424 P45459 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1728040 T3848 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@142f0c0e main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1728039 T3840 C1425 P35206 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1728042 T3852 C1422 P26175 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@165324f3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@63e0fab5),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@165324f3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@63e0fab5),segFN=segments_3,generation=3}
[junit4:junit4] 2> 1728042 T3883 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@253cdf6d main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1728044 T3852 C1422 P26175 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 1728043 T3840 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 17
[junit4:junit4] 2> 1728045 T3852 C1422 P26175 oass.SolrIndexSearcher.<init> Opening Searcher@5f73411a main
[junit4:junit4] 2> 1728044 T3870 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 18
[junit4:junit4] 2> 1728046 T3852 C1422 P26175 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1728047 T3864 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5f73411a main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1728048 T3852 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 10
[junit4:junit4] 2> 1728049 T3869 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 28
[junit4:junit4] 2> 1728050 T3788 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1728053 T3825 C1423 P22961 oasc.SolrCore.execute [collection1] webapp=/o_bh/e path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4] 2> 1728056 T3853 C1422 P26175 oasc.SolrCore.execute [collection1] webapp=/o_bh/e path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=1
[junit4:junit4] 2> 1728058 T3841 C1425 P35206 oasc.SolrCore.execute [collection1] webapp=/o_bh/e path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4] 2> 1728061 T3871 C1424 P45459 oasc.SolrCore.execute [collection1] webapp=/o_bh/e path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4] 2> 1730067 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1438340752791830528)} 0 2
[junit4:junit4] 2> 1730078 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={update.distrib=FROMLEADER&_version_=-1438340752796024832&update.from=http://127.0.0.1:22961/o_bh/e/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1438340752796024832)} 0 2
[junit4:junit4] 2> 1730083 T3872 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={update.distrib=FROMLEADER&_version_=-1438340752802316288&update.from=http://127.0.0.1:35206/o_bh/e/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1438340752802316288)} 0 2
[junit4:junit4] 2> 1730084 T3842 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={update.distrib=TOLEADER&wt=javabin&version=2} {deleteByQuery=*:* (-1438340752802316288)} 0 8
[junit4:junit4] 2> 1730084 T3826 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1438340752796024832)} 0 14
[junit4:junit4] 2> 1730088 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[0 (1438340752814899200)]} 0 1
[junit4:junit4] 2> 1730098 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[0 (1438340752821190656)]} 0 1
[junit4:junit4] 2> 1730099 T3824 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:45459/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[0 (1438340752821190656)]} 0 5
[junit4:junit4] 2> 1730100 T3869 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[0]} 0 9
[junit4:junit4] 2> 1730104 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[1 (1438340752830627840)]} 0 1
[junit4:junit4] 2> 1730111 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[1 (1438340752834822144)]} 0 1
[junit4:junit4] 2> 1730112 T3826 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[1 (1438340752834822144)]} 0 5
[junit4:junit4] 2> 1730116 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[2 (1438340752843210752)]} 0 1
[junit4:junit4] 2> 1730125 T3872 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[2 (1438340752849502208)]} 0 1
[junit4:junit4] 2> 1730126 T3842 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[2 (1438340752849502208)]} 0 5
[junit4:junit4] 2> 1730127 T3826 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[2]} 0 8
[junit4:junit4] 2> 1730131 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[3 (1438340752859987968)]} 0 1
[junit4:junit4] 2> 1730141 T3872 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[3 (1438340752866279424)]} 0 1
[junit4:junit4] 2> 1730142 T3840 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:45459/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[3 (1438340752866279424)]} 0 5
[junit4:junit4] 2> 1730143 T3869 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[3]} 0 9
[junit4:junit4] 2> 1730146 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[4 (1438340752874668032)]} 0 1
[junit4:junit4] 2> 1730153 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[4 (1438340752878862336)]} 0 1
[junit4:junit4] 2> 1730154 T3826 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[4 (1438340752878862336)]} 0 5
[junit4:junit4] 2> 1730157 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[5 (1438340752886202368)]} 0 1
[junit4:junit4] 2> 1730165 T3872 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[5 (1438340752892493824)]} 0 1
[junit4:junit4] 2> 1730166 T3842 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[5 (1438340752892493824)]} 0 5
[junit4:junit4] 2> 1730167 T3826 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[5]} 0 8
[junit4:junit4] 2> 1730171 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[6 (1438340752900882432)]} 0 1
[junit4:junit4] 2> 1730181 T3872 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[6 (1438340752908222464)]} 0 1
[junit4:junit4] 2> 1730182 T3842 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[6 (1438340752908222464)]} 0 5
[junit4:junit4] 2> 1730183 T3826 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[6]} 0 9
[junit4:junit4] 2> 1730187 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[7 (1438340752917659648)]} 0 1
[junit4:junit4] 2> 1730197 T3872 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[7 (1438340752924999680)]} 0 1
[junit4:junit4] 2> 1730198 T3842 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[7 (1438340752924999680)]} 0 5
[junit4:junit4] 2> 1730199 T3826 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[7]} 0 9
[junit4:junit4] 2> 1730203 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[8 (1438340752934436864)]} 0 1
[junit4:junit4] 2> 1730210 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[8 (1438340752938631168)]} 0 1
[junit4:junit4] 2> 1730211 T3826 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[8 (1438340752938631168)]} 0 5
[junit4:junit4] 2> 1730215 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[9 (1438340752947019776)]} 0 1
[junit4:junit4] 2> 1730224 T3872 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[9 (1438340752953311232)]} 0 1
[junit4:junit4] 2> 1730225 T3836 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:26175/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[9 (1438340752953311232)]} 0 5
[junit4:junit4] 2> 1730226 T3855 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[9]} 0 9
[junit4:junit4] 2> 1730230 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[10 (1438340752962748416)]} 0 1
[junit4:junit4] 2> 1730237 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10 (1438340752966942720)]} 0 1
[junit4:junit4] 2> 1730238 T3826 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[10 (1438340752966942720)]} 0 5
[junit4:junit4] 2> 1730242 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[11 (1438340752975331328)]} 0 1
[junit4:junit4] 2> 1730249 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[11 (1438340752979525632)]} 0 1
[junit4:junit4] 2> 1730250 T3820 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[11 (1438340752979525632)]} 0 5
[junit4:junit4] 2> 1730250 T3838 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[11]} 0 6
[junit4:junit4] 2> 1730254 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[12 (1438340752987914240)]} 0 1
[junit4:junit4] 2> 1730261 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[12 (1438340752992108544)]} 0 1
[junit4:junit4] 2> 1730262 T3826 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[12 (1438340752992108544)]} 0 5
[junit4:junit4] 2> 1730266 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[13 (1438340753000497152)]} 0 1
[junit4:junit4] 2> 1730275 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[13 (1438340753006788608)]} 0 1
[junit4:junit4] 2> 1730276 T3822 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:26175/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[13 (1438340753006788608)]} 0 5
[junit4:junit4] 2> 1730277 T3855 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[13]} 0 8
[junit4:junit4] 2> 1730281 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[14 (1438340753016225792)]} 0 1
[junit4:junit4] 2> 1730291 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[14 (1438340753023565824)]} 0 1
[junit4:junit4] 2> 1730292 T3824 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:45459/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[14 (1438340753023565824)]} 0 5
[junit4:junit4] 2> 1730292 T3869 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[14]} 0 8
[junit4:junit4] 2> 1730296 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[15 (1438340753031954432)]} 0 1
[junit4:junit4] 2> 1730305 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[15 (1438340753038245888)]} 0 1
[junit4:junit4] 2> 1730305 T3824 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:45459/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[15 (1438340753038245888)]} 0 4
[junit4:junit4] 2> 1730306 T3869 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[15]} 0 7
[junit4:junit4] 2> 1730310 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[16 (1438340753046634496)]} 0 1
[junit4:junit4] 2> 1730316 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[16 (1438340753050828800)]} 0 0
[junit4:junit4] 2> 1730317 T3826 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[16 (1438340753050828800)]} 0 4
[junit4:junit4] 2> 1730321 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[17 (1438340753058168832)]} 0 1
[junit4:junit4] 2> 1730327 T3872 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[17 (1438340753061314560)]} 0 1
[junit4:junit4] 2> 1730328 T3838 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[17 (1438340753061314560)]} 0 5
[junit4:junit4] 2> 1730331 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[18 (1438340753068654592)]} 0 1
[junit4:junit4] 2> 1730340 T3872 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[18 (1438340753074946048)]} 0 1
[junit4:junit4] 2> 1730340 T3840 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:45459/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[18 (1438340753074946048)]} 0 4
[junit4:junit4] 2> 1730341 T3869 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[18]} 0 7
[junit4:junit4] 2> 1730345 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[19 (1438340753083334656)]} 0 1
[junit4:junit4] 2> 1730351 T3872 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[19 (1438340753087528960)]} 0 0
[junit4:junit4] 2> 1730352 T3838 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[19 (1438340753087528960)]} 0 4
[junit4:junit4] 2> 1730356 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[20 (1438340753094868992)]} 0 1
[junit4:junit4] 2> 1730363 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[20 (1438340753099063296)]} 0 0
[junit4:junit4] 2> 1730363 T3826 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[20 (1438340753099063296)]} 0 4
[junit4:junit4] 2> 1730366 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[21 (1438340753106403328)]} 0 0
[junit4:junit4] 2> 1730375 T3872 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[21 (1438340753111646208)]} 0 1
[junit4:junit4] 2> 1730376 T3840 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:45459/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[21 (1438340753111646208)]} 0 5
[junit4:junit4] 2> 1730376 T3869 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[21]} 0 7
[junit4:junit4] 2> 1730380 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[22 (1438340753120034816)]} 0 1
[junit4:junit4] 2> 1730391 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[22 (1438340753128423424)]} 0 1
[junit4:junit4] 2> 1730392 T3824 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:45459/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[22 (1438340753128423424)]} 0 5
[junit4:junit4] 2> 1730393 T3869 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[22]} 0 10
[junit4:junit4] 2> 1730397 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[23 (1438340753137860608)]} 0 1
[junit4:junit4] 2> 1730413 T3872 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[23 (1438340753151492096)]} 0 1
[junit4:junit4] 2> 1730415 T3840 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:45459/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[23 (1438340753151492096)]} 0 7
[junit4:junit4] 2> 1730416 T3869 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[23]} 0 16
[junit4:junit4] 2> 1730420 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[24 (1438340753161977856)]} 0 1
[junit4:junit4] 2> 1730426 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[24 (1438340753165123584)]} 0 1
[junit4:junit4] 2> 1730427 T3826 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[24 (1438340753165123584)]} 0 5
[junit4:junit4] 2> 1730431 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[25 (1438340753173512192)]} 0 1
[junit4:junit4] 2> 1730440 T3872 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[25 (1438340753179803648)]} 0 1
[junit4:junit4] 2> 1730441 T3842 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[25 (1438340753179803648)]} 0 5
[junit4:junit4] 2> 1730442 T3826 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[25]} 0 9
[junit4:junit4] 2> 1730446 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[26 (1438340753189240832)]} 0 1
[junit4:junit4] 2> 1730453 T3872 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[26 (1438340753193435136)]} 0 1
[junit4:junit4] 2> 1730454 T3838 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[26 (1438340753193435136)]} 0 5
[junit4:junit4] 2> 1730458 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[27 (1438340753201823744)]} 0 1
[junit4:junit4] 2> 1730468 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[27 (1438340753209163776)]} 0 1
[junit4:junit4] 2> 1730469 T3824 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:45459/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[27 (1438340753209163776)]} 0 5
[junit4:junit4] 2> 1730470 T3869 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[27]} 0 9
[junit4:junit4] 2> 1730474 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[28 (1438340753218600960)]} 0 1
[junit4:junit4] 2> 1730483 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[28 (1438340753224892416)]} 0 1
[junit4:junit4] 2> 1730484 T3822 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:26175/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[28 (1438340753224892416)]} 0 5
[junit4:junit4] 2> 1730484 T3855 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[28]} 0 7
[junit4:junit4] 2> 1730488 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[29 (1438340753233281024)]} 0 1
[junit4:junit4] 2> 1730496 T3872 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[29 (1438340753238523904)]} 0 1
[junit4:junit4] 2> 1730497 T3840 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:45459/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[29 (1438340753238523904)]} 0 5
[junit4:junit4] 2> 1730497 T3869 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[29]} 0 7
[junit4:junit4] 2> 1730503 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[30 (1438340753246912512)]} 0 3
[junit4:junit4] 2> 1730512 T3872 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[30 (1438340753256349696)]} 0 0
[junit4:junit4] 2> 1730513 T3840 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:45459/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[30 (1438340753256349696)]} 0 4
[junit4:junit4] 2> 1730514 T3869 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[30]} 0 8
[junit4:junit4] 2> 1730518 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[31 (1438340753264738304)]} 0 1
[junit4:junit4] 2> 1730526 T3872 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[31 (1438340753269981184)]} 0 1
[junit4:junit4] 2> 1730527 T3836 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:26175/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[31 (1438340753269981184)]} 0 5
[junit4:junit4] 2> 1730528 T3855 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[31]} 0 8
[junit4:junit4] 2> 1730532 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[32 (1438340753279418368)]} 0 1
[junit4:junit4] 2> 1730542 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[32 (1438340753287806976)]} 0 0
[junit4:junit4] 2> 1730544 T3824 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:45459/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[32 (1438340753287806976)]} 0 5
[junit4:junit4] 2> 1730545 T3869 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[32]} 0 9
[junit4:junit4] 2> 1730549 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[33 (1438340753297244160)]} 0 1
[junit4:junit4] 2> 1730557 T3872 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[33 (1438340753302487040)]} 0 1
[junit4:junit4] 2> 1730558 T3842 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[33 (1438340753302487040)]} 0 5
[junit4:junit4] 2> 1730559 T3826 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[33]} 0 8
[junit4:junit4] 2> 1730563 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[34 (1438340753311924224)]} 0 1
[junit4:junit4] 2> 1730569 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[34 (1438340753315069952)]} 0 1
[junit4:junit4] 2> 1730570 T3826 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[34 (1438340753315069952)]} 0 5
[junit4:junit4] 2> 1730574 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[35 (1438340753323458560)]} 0 1
[junit4:junit4] 2> 1730583 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[35 (1438340753330798592)]} 0 0
[junit4:junit4] 2> 1730584 T3820 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[35 (1438340753330798592)]} 0 4
[junit4:junit4] 2> 1730585 T3838 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[35]} 0 8
[junit4:junit4] 2> 1730589 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[36 (1438340753339187200)]} 0 1
[junit4:junit4] 2> 1730596 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[36 (1438340753344430080)]} 0 0
[junit4:junit4] 2> 1730597 T3820 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[36 (1438340753344430080)]} 0 4
[junit4:junit4] 2> 1730598 T3838 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[36]} 0 7
[junit4:junit4] 2> 1730601 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[37 (1438340753352818688)]} 0 0
[junit4:junit4] 2> 1730610 T3872 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[37 (1438340753358061568)]} 0 1
[junit4:junit4] 2> 1730611 T3836 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:26175/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[37 (1438340753358061568)]} 0 5
[junit4:junit4] 2> 1730611 T3855 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[37]} 0 7
[junit4:junit4] 2> 1730615 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[38 (1438340753366450176)]} 0 1
[junit4:junit4] 2> 1730622 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[38 (1438340753370644480)]} 0 1
[junit4:junit4] 2> 1730623 T3826 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[38 (1438340753370644480)]} 0 5
[junit4:junit4] 2> 1730627 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[39 (1438340753379033088)]} 0 1
[junit4:junit4] 2> 1730636 T3872 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[39 (1438340753385324544)]} 0 1
[junit4:junit4] 2> 1730637 T3842 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[39 (1438340753385324544)]} 0 5
[junit4:junit4] 2> 1730637 T3826 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[39]} 0 7
[junit4:junit4] 2> 1730641 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[40 (1438340753393713152)]} 0 1
[junit4:junit4] 2> 1730650 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[40 (1438340753401053184)]} 0 0
[junit4:junit4] 2> 1730652 T3824 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:45459/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[40 (1438340753401053184)]} 0 5
[junit4:junit4] 2> 1730652 T3869 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[40]} 0 8
[junit4:junit4] 2> 1730656 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[41 (1438340753409441792)]} 0 1
[junit4:junit4] 2> 1730666 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[41 (1438340753416781824)]} 0 1
[junit4:junit4] 2> 1730667 T3824 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:45459/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[41 (1438340753416781824)]} 0 5
[junit4:junit4] 2> 1730668 T3869 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[41]} 0 9
[junit4:junit4] 2> 1730672 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[42 (1438340753426219008)]} 0 1
[junit4:junit4] 2> 1730679 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[42 (1438340753430413312)]} 0 1
[junit4:junit4] 2> 1730682 T3826 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[42 (1438340753430413312)]} 0 7
[junit4:junit4] 2> 1730687 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[43 (1438340753441947648)]} 0 1
[junit4:junit4] 2> 1730694 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[43 (1438340753446141952)]} 0 1
[junit4:junit4] 2> 1730695 T3826 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[43 (1438340753446141952)]} 0 5
[junit4:junit4] 2> 1730699 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[44 (1438340753454530560)]} 0 1
[junit4:junit4] 2> 1730709 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[44 (1438340753461870592)]} 0 1
[junit4:junit4] 2> 1730710 T3824 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:45459/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[44 (1438340753461870592)]} 0 5
[junit4:junit4] 2> 1730711 T3869 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[44]} 0 9
[junit4:junit4] 2> 1730715 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[45 (1438340753471307776)]} 0 1
[junit4:junit4] 2> 1730722 T3872 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[45 (1438340753475502080)]} 0 1
[junit4:junit4] 2> 1730723 T3838 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[45 (1438340753475502080)]} 0 5
[junit4:junit4] 2> 1730727 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[46 (1438340753483890688)]} 0 1
[junit4:junit4] 2> 1730737 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[46 (1438340753491230720)]} 0 1
[junit4:junit4] 2> 1730738 T3822 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:26175/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[46 (1438340753491230720)]} 0 5
[junit4:junit4] 2> 1730739 T3855 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[46]} 0 9
[junit4:junit4] 2> 1730743 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[47 (1438340753500667904)]} 0 1
[junit4:junit4] 2> 1730750 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[47 (1438340753504862208)]} 0 1
[junit4:junit4] 2> 1730751 T3826 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[47 (1438340753504862208)]} 0 5
[junit4:junit4] 2> 1730755 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[48 (1438340753513250816)]} 0 1
[junit4:junit4] 2> 1730765 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[48 (1438340753520590848)]} 0 1
[junit4:junit4] 2> 1730766 T3822 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:26175/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[48 (1438340753520590848)]} 0 5
[junit4:junit4] 2> 1730767 T3855 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[48]} 0 9
[junit4:junit4] 2> 1730771 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[49 (1438340753530028032)]} 0 1
[junit4:junit4] 2> 1730781 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[49 (1438340753537368064)]} 0 1
[junit4:junit4] 2> 1730782 T3824 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:45459/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[49 (1438340753537368064)]} 0 5
[junit4:junit4] 2> 1730783 T3869 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[49]} 0 9
[junit4:junit4] 2> 1730786 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[50 (1438340753545756672)]} 0 1
[junit4:junit4] 2> 1730795 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[50 (1438340753552048128)]} 0 1
[junit4:junit4] 2> 1730796 T3820 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[50 (1438340753552048128)]} 0 5
[junit4:junit4] 2> 1730797 T3838 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[50]} 0 8
[junit4:junit4] 2> 1730799 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[51 (1438340753560436736)]} 0 0
[junit4:junit4] 2> 1730807 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[51 (1438340753565679616)]} 0 0
[junit4:junit4] 2> 1730808 T3822 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:26175/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[51 (1438340753565679616)]} 0 4
[junit4:junit4] 2> 1730809 T3855 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[51]} 0 7
[junit4:junit4] 2> 1730812 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[52 (1438340753574068224)]} 0 0
[junit4:junit4] 2> 1730819 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[52 (1438340753577213952)]} 0 1
[junit4:junit4] 2> 1730820 T3826 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[52 (1438340753577213952)]} 0 5
[junit4:junit4] 2> 1730824 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[53 (1438340753585602560)]} 0 1
[junit4:junit4] 2> 1730833 T3872 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[53 (1438340753591894016)]} 0 1
[junit4:junit4] 2> 1730834 T3840 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:45459/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[53 (1438340753591894016)]} 0 5
[junit4:junit4] 2> 1730835 T3869 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[53]} 0 8
[junit4:junit4] 2> 1730839 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[54 (1438340753601331200)]} 0 1
[junit4:junit4] 2> 1730848 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[54 (1438340753608671232)]} 0 0
[junit4:junit4] 2> 1730850 T3822 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:26175/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[54 (1438340753608671232)]} 0 5
[junit4:junit4] 2> 1730851 T3855 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[54]} 0 9
[junit4:junit4] 2> 1730854 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[55 (1438340753617059840)]} 0 1
[junit4:junit4] 2> 1730861 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[55 (1438340753621254144)]} 0 1
[junit4:junit4] 2> 1730861 T3826 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[55 (1438340753621254144)]} 0 4
[junit4:junit4] 2> 1730864 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[56 (1438340753628594176)]} 0 0
[junit4:junit4] 2> 1730876 T3872 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[56 (1438340753634885632)]} 0 1
[junit4:junit4] 2> 1730877 T3842 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[56 (1438340753634885632)]} 0 8
[junit4:junit4] 2> 1730878 T3826 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[56]} 0 11
[junit4:junit4] 2> 1730882 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[57 (1438340753646419968)]} 0 1
[junit4:junit4] 2> 1730892 T3872 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[57 (1438340753653760000)]} 0 1
[junit4:junit4] 2> 1730893 T3836 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:26175/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[57 (1438340753653760000)]} 0 5
[junit4:junit4] 2> 1730894 T3855 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[57]} 0 9
[junit4:junit4] 2> 1730898 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[58 (1438340753663197184)]} 0 1
[junit4:junit4] 2> 1730907 T3872 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[58 (1438340753670537216)]} 0 0
[junit4:junit4] 2> 1730908 T3836 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:26175/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[58 (1438340753670537216)]} 0 4
[junit4:junit4] 2> 1730909 T3855 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[58]} 0 8
[junit4:junit4] 2> 1730913 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[59 (1438340753678925824)]} 0 1
[junit4:junit4] 2> 1730923 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:22961/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[59 (1438340753686265856)]} 0 1
[junit4:junit4] 2> 1730924 T3820 C1423 P22961 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[59 (1438340753686265856)]} 0 5
[junit4:junit4] 2> 1730925 T3838 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[59]} 0 9
[junit4:junit4] 2> 1730929 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[60 (1438340753695703040)]} 0 1
[junit4:junit4] 2> 1730938 T3872 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:35206/o_bh/e/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[60 (1438340753701994496)]} 0 1
[junit4:junit4] 2> 1730939 T3840 C1425 P35206 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={distrib.from=http://127.0.0.1:45459/o_bh/e/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[60 (1438340753701994496)]} 0 5
[junit4:junit4] 2> 1730940 T3869 C1424 P45459 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[60]} 0 8
[junit4:junit4] 2> 1730944 T3800 C1426 P25871 oasup.LogUpdateProcessor.finish [collection1] webapp=/o_bh/e path=/update params={wt=javabin&version=2} {add=[61 (1438340753711431680)]} 0 1
[junit4:junit4] 2> 1730951 T3854 C1422 P26175 oasup.LogUpdateProcessor.finish [col
[...truncated too long message...]
2> 1940617 T3788 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 1940618 T3788 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 1940619 T3788 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 1940621 T3788 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 1940622 T3788 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 1940623 T3788 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty4 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty4;done=false>>]
[junit4:junit4] 2> 1940623 T3788 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty4
[junit4:junit4] 2> 1940624 T3788 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty4/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty4/index;done=false>>]
[junit4:junit4] 2> 1940624 T3788 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511/jetty4/index
[junit4:junit4] 2> 1940625 T3967 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89896294909280268-127.0.0.1:45459_o_bh%2Fe-n_0000000004) am no longer a leader.
[junit4:junit4] 2> 1940626 T3879 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> 1940626 T3879 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 1940627 T3788 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/o_bh/e,null}
[junit4:junit4] 2> 1940627 T3879 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 1940699 T3788 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 1940701 T3788 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:34193 34193
[junit4:junit4] 2> 1940856 T3862 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 1940926 T3862 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> 1940927 T3862 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 1940928 T3788 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 25871
[junit4:junit4] 2> !!!! WARNING: best effort to remove /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371708601511 FAILED !!!!!
[junit4:junit4] 2> 1940929 T3788 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 1940929 T3788 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:34193 34193
[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=BCC412BA92B002D4 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=cs_CZ -Dtests.timezone=America/Grand_Turk -Dtests.file.encoding=ISO-8859-1
[junit4:junit4] ERROR 244s J1 | ChaosMonkeyShardSplitTest.testDistribSearch <<<
[junit4:junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:22961/o_bh/e returned non ok status:500, message:Server Error
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([BCC412BA92B002D4:3D229CA2E5EF62E8]:0)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4:junit4] > at org.apache.solr.cloud.ShardSplitTest.splitShard(ShardSplitTest.java:228)
[junit4:junit4] > at org.apache.solr.cloud.ChaosMonkeyShardSplitTest.doTest(ChaosMonkeyShardSplitTest.java:136)
[junit4:junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:835)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2> 1940949 T3788 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> NOTE: test params are: codec=Lucene40, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=cs_CZ, timezone=America/Grand_Turk
[junit4:junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_21 (64-bit)/cpus=16,threads=2,free=316422288,total=535822336
[junit4:junit4] 2> NOTE: All tests run in this JVM: [SuggesterWFSTTest, HighlighterConfigTest, TestArbitraryIndexDir, TestStressReorder, TestBinaryField, TestLMJelinekMercerSimilarityFactory, TestFiltering, SpellPossibilityIteratorTest, TestPostingsSolrHighlighter, SuggesterTSTTest, SpellCheckComponentTest, ZkSolrClientTest, DefaultValueUpdateProcessorTest, DOMUtilTest, TermVectorComponentDistributedTest, TestStressLucene, ConvertedLegacyTest, TestCSVResponseWriter, TestQueryTypes, IndexBasedSpellCheckerTest, TestSolr4Spatial, TestHashPartitioner, JSONWriterTest, MultiTermTest, TestRTGBase, ZkNodePropsTest, TestSchemaVersionResource, IndexReaderFactoryTest, TestDFRSimilarityFactory, TestPropInject, TestDefaultSimilarityFactory, SolrIndexConfigTest, CopyFieldTest, CurrencyFieldOpenExchangeTest, TestFastOutputStream, CollectionsAPIDistributedZkTest, TestReload, XsltUpdateRequestHandlerTest, TestLuceneMatchVersion, TestBinaryResponseWriter, TestFieldTypeResource, NotRequiredUniqueKeyTest, TestAnalyzedSuggestions, IndexSchemaRuntimeFieldTest, SolrCoreCheckLockOnStartupTest, TestSystemIdResolver, SolrPluginUtilsTest, CurrencyFieldXmlFileTest, TestOmitPositions, TestFieldResource, TestDynamicFieldResource, TestJmxIntegration, SimplePostToolTest, URLClassifyProcessorTest, NumericFieldsTest, FileUtilsTest, DirectSolrSpellCheckerTest, TestMaxScoreQueryParser, SpellCheckCollatorTest, LeaderElectionIntegrationTest, RequestHandlersTest, ChaosMonkeySafeLeaderTest, DirectUpdateHandlerTest, UpdateParamsTest, TestQuerySenderNoQuery, TestCSVLoader, OutputWriterTest, TestSerializedLuceneMatchVersion, TimeZoneUtilsTest, CoreContainerCoreInitFailuresTest, TestFieldTypeCollectionResource, BasicDistributedZk2Test, SyncSliceTest, OpenCloseCoreStressTest, OverseerTest, BasicZkTest, TestZkChroot, ShardRoutingCustomTest, TestDistributedSearch, AutoCommitTest, TestDistributedGrouping, TestRecovery, DistributedSpellCheckComponentTest, ZkControllerTest, TestJoin, SolrCmdDistributorTest, QueryElevationComponentTest, TestFunctionQuery, BasicFunctionalityTest, TestBadConfig, DistributedQueryElevationComponentTest, TestCoreDiscovery, SignatureUpdateProcessorFactoryTest, TestExtendedDismaxParser, TestFoldingMultitermQuery, SuggesterTest, NoCacheHeaderTest, TestAtomicUpdateErrorCases, QueryEqualityTest, TestRemoteStreaming, DistanceFunctionTest, TestSurroundQueryParser, DisMaxRequestHandlerTest, TestQueryUtils, DocumentAnalysisRequestHandlerTest, XmlUpdateRequestHandlerTest, PathHierarchyTokenizerFactoryTest, TestIndexingPerformance, MoreLikeThisHandlerTest, FieldAnalysisRequestHandlerTest, FastVectorHighlighterTest, UpdateRequestProcessorFactoryTest, TestPartialUpdateDeduplication, PingRequestHandlerTest, BadComponentTest, TestMergePolicyConfig, TestSolrDeletionPolicy2, SampleTest, TestDocSet, MinimalSchemaTest, TestElisionMultitermQuery, TestConfig, TestFuzzyAnalyzedSuggestions, DirectSolrConnectionTest, TestPhraseSuggestions, TestCodecSupport, SynonymTokenizerTest, EchoParamsTest, TestPerFieldSimilarity, TestNumberUtils, TestLMDirichletSimilarityFactory, TestBM25SimilarityFactory, TestFastWriter, LegacyHTMLStripCharFilterTest, TestJmxMonitoredMap, ResourceLoaderTest, OpenExchangeRatesOrgProviderTest, PluginInfoTest, TestFastLRUCache, DateMathParserTest, TestSolrXMLSerializer, PrimUtilsTest, TestSuggestSpellingConverter, DateFieldTest, ClusterStateTest, TestSolrJ, TestUtils, TestDocumentBuilder, SystemInfoHandlerTest, SolrTestCaseJ4Test, ChaosMonkeyShardSplitTest]
[junit4:junit4] Completed on J1 in 243.59s, 1 test, 1 error <<< FAILURES!
[...truncated 10 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:386: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:366: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/build.xml:181: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/solr/common-build.xml:437: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:1243: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-trunk-Java7/lucene/common-build.xml:887: There were test failures: 297 suites, 1252 tests, 1 error, 13 ignored (7 assumptions)
Total time: 52 minutes 10 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure