You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2013/06/21 01:50:26 UTC
[JENKINS] Lucene-Solr-4.x-Linux (64bit/jdk1.8.0-ea-b93) - Build #
6159 - Failure!
Build: http://jenkins.thetaphi.de/job/Lucene-Solr-4.x-Linux/6159/
Java: 64bit/jdk1.8.0-ea-b93 -XX:-UseCompressedOops -XX:+UseG1GC
1 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeyShardSplitTest.testDistribSearch
Error Message:
Server at http://127.0.0.1:41640/fm_d/pb 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:41640/fm_d/pb returned non ok status:500, message:Server Error
at __randomizedtesting.SeedInfo.seed([F8EA99248C2D0492:790C173CFB7264AE]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:387)
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:491)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:724)
Build Log:
[...truncated 10251 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.ChaosMonkeyShardSplitTest
[junit4:junit4] 2> 913904 T2932 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /fm_d/pb
[junit4:junit4] 2> 913908 T2932 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./solrtest-ChaosMonkeyShardSplitTest-1371772053733
[junit4:junit4] 2> 913909 T2932 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 913909 T2933 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 914009 T2932 oasc.ZkTestServer.run start zk server on port:54568
[junit4:junit4] 2> 914010 T2932 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 914089 T2939 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5819cead name:ZooKeeperConnection Watcher:127.0.0.1:54568 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 914089 T2932 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 914090 T2932 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 914094 T2932 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 914095 T2941 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@56de3bde name:ZooKeeperConnection Watcher:127.0.0.1:54568/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 914095 T2932 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 914096 T2932 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 914098 T2932 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 914100 T2932 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 914102 T2932 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 914104 T2932 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 914104 T2932 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 914108 T2932 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 914108 T2932 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 914111 T2932 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 914112 T2932 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 914114 T2932 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 914114 T2932 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 914116 T2932 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 914117 T2932 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 914119 T2932 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 914119 T2932 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 914121 T2932 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 914122 T2932 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 914124 T2932 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 914124 T2932 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 914126 T2932 oasc.AbstractZkTestCase.putConfig put /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 914127 T2932 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 914202 T2932 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 914226 T2932 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:50852
[junit4:junit4] 2> 914227 T2932 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 914227 T2932 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 914227 T2932 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1371772053955
[junit4:junit4] 2> 914228 T2932 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1371772053955/solr.xml
[junit4:junit4] 2> 914228 T2932 oasc.CoreContainer.<init> New CoreContainer 1438052799
[junit4:junit4] 2> 914228 T2932 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1371772053955/'
[junit4:junit4] 2> 914229 T2932 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1371772053955/'
[junit4:junit4] 2> 914275 T2932 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 914275 T2932 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 914275 T2932 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 914276 T2932 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 914276 T2932 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 914276 T2932 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 914276 T2932 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 914277 T2932 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 914277 T2932 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 914277 T2932 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 914281 T2932 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 914281 T2932 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:54568/solr
[junit4:junit4] 2> 914281 T2932 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 914282 T2932 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 914283 T2952 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7edcdab9 name:ZooKeeperConnection Watcher:127.0.0.1:54568 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 914284 T2932 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 914285 T2932 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 914288 T2932 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 914290 T2954 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3a9e897d name:ZooKeeperConnection Watcher:127.0.0.1:54568/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 914290 T2932 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 914291 T2932 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 914293 T2932 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 914294 T2932 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 914295 T2932 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:50852_fm_d%2Fpb
[junit4:junit4] 2> 914296 T2932 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:50852_fm_d%2Fpb
[junit4:junit4] 2> 914298 T2932 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 914301 T2932 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 914302 T2932 oasc.Overseer.start Overseer (id=89900453313576963-127.0.0.1:50852_fm_d%2Fpb-n_0000000000) starting
[junit4:junit4] 2> 914304 T2932 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 914306 T2956 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 914306 T2932 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 914308 T2932 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 914309 T2932 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 914311 T2955 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 914314 T2957 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 914314 T2957 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 915814 T2955 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 915814 T2955 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50852/fm_d/pb",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "node_name":"127.0.0.1:50852_fm_d%2Fpb"}
[junit4:junit4] 2> 915814 T2955 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 915814 T2955 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 915817 T2954 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> 916316 T2957 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1371772053955/collection1
[junit4:junit4] 2> 916316 T2957 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 916317 T2957 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 916317 T2957 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 916318 T2957 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1371772053955/collection1/'
[junit4:junit4] 2> 916319 T2957 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1371772053955/collection1/lib/README' to classloader
[junit4:junit4] 2> 916319 T2957 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1371772053955/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 916361 T2957 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 916432 T2957 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 916433 T2957 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 916445 T2957 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 916864 T2957 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 916868 T2957 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 916871 T2957 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 916881 T2957 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 916907 T2957 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 916907 T2957 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1371772053955/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/control/data/
[junit4:junit4] 2> 916908 T2957 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4c23611e
[junit4:junit4] 2> 916908 T2957 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 916909 T2957 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/control/data
[junit4:junit4] 2> 916909 T2957 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/control/data/index/
[junit4:junit4] 2> 916909 T2957 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 916910 T2957 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/control/data/index
[junit4:junit4] 2> 916912 T2957 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@55f0b669 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2d41f0bd),segFN=segments_1,generation=1}
[junit4:junit4] 2> 916912 T2957 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 916915 T2957 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 916915 T2957 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 916916 T2957 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 916917 T2957 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 916917 T2957 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 916918 T2957 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 916918 T2957 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 916919 T2957 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 916919 T2957 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 916922 T2957 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 916926 T2957 oass.SolrIndexSearcher.<init> Opening Searcher@2f8eb0da main
[junit4:junit4] 2> 916926 T2957 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/control/data/tlog
[junit4:junit4] 2> 916927 T2957 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 916927 T2957 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 916931 T2958 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2f8eb0da main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 916933 T2957 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 916934 T2957 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:50852/fm_d/pb collection:control_collection shard:shard1
[junit4:junit4] 2> 916948 T2957 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 916953 T2957 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 916955 T2957 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 916956 T2957 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 916956 T2957 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:50852/fm_d/pb/collection1/
[junit4:junit4] 2> 916956 T2957 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 916956 T2957 oasc.SyncStrategy.syncToMe http://127.0.0.1:50852/fm_d/pb/collection1/ has no replicas
[junit4:junit4] 2> 916956 T2957 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:50852/fm_d/pb/collection1/
[junit4:junit4] 2> 916956 T2957 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 917320 T2955 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 917368 T2954 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> 917413 T2957 oasc.ZkController.register We are http://127.0.0.1:50852/fm_d/pb/collection1/ and leader is http://127.0.0.1:50852/fm_d/pb/collection1/
[junit4:junit4] 2> 917413 T2957 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:50852/fm_d/pb
[junit4:junit4] 2> 917413 T2957 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 917414 T2957 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 917414 T2957 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 917415 T2957 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 917416 T2932 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 917416 T2932 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 917416 T2932 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 917420 T2932 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 917421 T2932 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 917422 T2961 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@383ff214 name:ZooKeeperConnection Watcher:127.0.0.1:54568/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 917422 T2932 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 917423 T2932 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 917425 T2932 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 917492 T2932 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 917495 T2932 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:34395
[junit4:junit4] 2> 917495 T2932 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 917496 T2932 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 917496 T2932 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1371772057249
[junit4:junit4] 2> 917496 T2932 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1371772057249/solr.xml
[junit4:junit4] 2> 917496 T2932 oasc.CoreContainer.<init> New CoreContainer 278560750
[junit4:junit4] 2> 917497 T2932 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1371772057249/'
[junit4:junit4] 2> 917497 T2932 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1371772057249/'
[junit4:junit4] 2> 917540 T2932 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 917541 T2932 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 917541 T2932 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 917541 T2932 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 917541 T2932 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 917542 T2932 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 917542 T2932 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 917542 T2932 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 917542 T2932 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 917542 T2932 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 917546 T2932 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 917546 T2932 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:54568/solr
[junit4:junit4] 2> 917546 T2932 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 917547 T2932 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 917548 T2972 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2d1a678e name:ZooKeeperConnection Watcher:127.0.0.1:54568 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 917549 T2932 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 917551 T2932 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 917554 T2932 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 917555 T2974 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1f625a1b name:ZooKeeperConnection Watcher:127.0.0.1:54568/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 917555 T2932 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 917558 T2932 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 918560 T2932 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:34395_fm_d%2Fpb
[junit4:junit4] 2> 918561 T2932 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:34395_fm_d%2Fpb
[junit4:junit4] 2> 918563 T2974 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 918563 T2961 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 918563 T2954 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 918564 T2954 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> 918568 T2975 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 918569 T2975 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 918875 T2955 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 918875 T2955 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:50852/fm_d/pb",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "node_name":"127.0.0.1:50852_fm_d%2Fpb"}
[junit4:junit4] 2> 918878 T2955 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "core_node_name":"2",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:34395/fm_d/pb",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "node_name":"127.0.0.1:34395_fm_d%2Fpb"}
[junit4:junit4] 2> 918878 T2955 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 918878 T2955 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 918881 T2961 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> 918881 T2954 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> 918881 T2974 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> 919570 T2975 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1371772057249/collection1
[junit4:junit4] 2> 919570 T2975 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 919571 T2975 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 919571 T2975 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 919572 T2975 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1371772057249/collection1/'
[junit4:junit4] 2> 919573 T2975 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1371772057249/collection1/lib/README' to classloader
[junit4:junit4] 2> 919573 T2975 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1371772057249/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 919615 T2975 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 919645 T2975 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 919646 T2975 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 919654 T2975 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 919978 T2975 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 919980 T2975 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 919981 T2975 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 919984 T2975 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 920000 T2975 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 920001 T2975 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1371772057249/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty1/
[junit4:junit4] 2> 920001 T2975 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4c23611e
[junit4:junit4] 2> 920001 T2975 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 920002 T2975 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty1
[junit4:junit4] 2> 920002 T2975 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty1/index/
[junit4:junit4] 2> 920002 T2975 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 920002 T2975 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty1/index
[junit4:junit4] 2> 920004 T2975 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5153b9df lockFactory=org.apache.lucene.store.NativeFSLockFactory@568f2300),segFN=segments_1,generation=1}
[junit4:junit4] 2> 920004 T2975 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 920006 T2975 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 920006 T2975 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 920006 T2975 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 920007 T2975 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 920007 T2975 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 920007 T2975 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 920007 T2975 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 920008 T2975 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 920008 T2975 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 920010 T2975 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 920012 T2975 oass.SolrIndexSearcher.<init> Opening Searcher@73ded34b main
[junit4:junit4] 2> 920012 T2975 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty1/tlog
[junit4:junit4] 2> 920013 T2975 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 920013 T2975 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 920017 T2976 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@73ded34b main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 920019 T2975 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 920019 T2975 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:34395/fm_d/pb collection:collection1 shard:shard2
[junit4:junit4] 2> 920020 T2975 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 920073 T2975 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 920075 T2975 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 920075 T2975 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 920076 T2975 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:34395/fm_d/pb/collection1/
[junit4:junit4] 2> 920076 T2975 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 920076 T2975 oasc.SyncStrategy.syncToMe http://127.0.0.1:34395/fm_d/pb/collection1/ has no replicas
[junit4:junit4] 2> 920076 T2975 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:34395/fm_d/pb/collection1/
[junit4:junit4] 2> 920076 T2975 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 920386 T2955 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 920392 T2974 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> 920392 T2961 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> 920392 T2954 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> 920432 T2975 oasc.ZkController.register We are http://127.0.0.1:34395/fm_d/pb/collection1/ and leader is http://127.0.0.1:34395/fm_d/pb/collection1/
[junit4:junit4] 2> 920433 T2975 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:34395/fm_d/pb
[junit4:junit4] 2> 920433 T2975 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 920433 T2975 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 920433 T2975 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 920435 T2975 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 920436 T2932 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 920436 T2932 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 920436 T2932 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 920510 T2932 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 920512 T2932 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:41640
[junit4:junit4] 2> 920514 T2932 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 920514 T2932 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 920514 T2932 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1371772060264
[junit4:junit4] 2> 920514 T2932 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1371772060264/solr.xml
[junit4:junit4] 2> 920515 T2932 oasc.CoreContainer.<init> New CoreContainer 398741202
[junit4:junit4] 2> 920515 T2932 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1371772060264/'
[junit4:junit4] 2> 920515 T2932 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1371772060264/'
[junit4:junit4] 2> 920558 T2932 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 920559 T2932 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 920559 T2932 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 920559 T2932 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 920559 T2932 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 920559 T2932 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 920560 T2932 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 920560 T2932 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 920560 T2932 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 920560 T2932 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 920564 T2932 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 920564 T2932 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:54568/solr
[junit4:junit4] 2> 920564 T2932 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 920565 T2932 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 920567 T2988 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3b5c3a25 name:ZooKeeperConnection Watcher:127.0.0.1:54568 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 920568 T2932 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 920569 T2932 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 920573 T2932 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 920574 T2990 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@451cdb75 name:ZooKeeperConnection Watcher:127.0.0.1:54568/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 920574 T2932 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 920577 T2932 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 921580 T2932 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:41640_fm_d%2Fpb
[junit4:junit4] 2> 921581 T2932 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:41640_fm_d%2Fpb
[junit4:junit4] 2> 921583 T2961 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 921583 T2990 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 921584 T2961 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> 921584 T2954 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 921584 T2954 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> 921584 T2974 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 921584 T2974 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> 921591 T2991 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 921591 T2991 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 921908 T2955 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 921909 T2955 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "core_node_name":"2",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:34395/fm_d/pb",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "node_name":"127.0.0.1:34395_fm_d%2Fpb"}
[junit4:junit4] 2> 921912 T2955 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:41640/fm_d/pb",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "node_name":"127.0.0.1:41640_fm_d%2Fpb"}
[junit4:junit4] 2> 921912 T2955 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 921913 T2955 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 921916 T2974 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> 921916 T2961 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> 921916 T2954 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> 921916 T2990 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> 922593 T2991 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1371772060264/collection1
[junit4:junit4] 2> 922593 T2991 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 922593 T2991 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 922594 T2991 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 922594 T2991 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1371772060264/collection1/'
[junit4:junit4] 2> 922595 T2991 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1371772060264/collection1/lib/README' to classloader
[junit4:junit4] 2> 922595 T2991 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1371772060264/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 922621 T2991 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 922661 T2991 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 922663 T2991 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 922671 T2991 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 922987 T2991 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 922991 T2991 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 922992 T2991 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 922996 T2991 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 923014 T2991 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 923014 T2991 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1371772060264/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty2/
[junit4:junit4] 2> 923014 T2991 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4c23611e
[junit4:junit4] 2> 923015 T2991 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 923015 T2991 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty2
[junit4:junit4] 2> 923016 T2991 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty2/index/
[junit4:junit4] 2> 923016 T2991 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 923016 T2991 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty2/index
[junit4:junit4] 2> 923017 T2991 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3dc3c1e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2ff84037),segFN=segments_1,generation=1}
[junit4:junit4] 2> 923018 T2991 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 923019 T2991 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 923020 T2991 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 923020 T2991 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 923021 T2991 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 923021 T2991 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 923021 T2991 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 923021 T2991 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 923022 T2991 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 923022 T2991 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 923024 T2991 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 923026 T2991 oass.SolrIndexSearcher.<init> Opening Searcher@7f5b170f main
[junit4:junit4] 2> 923026 T2991 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty2/tlog
[junit4:junit4] 2> 923027 T2991 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 923027 T2991 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 923030 T2992 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7f5b170f main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 923032 T2991 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 923032 T2991 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:41640/fm_d/pb collection:collection1 shard:shard1
[junit4:junit4] 2> 923033 T2991 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 923036 T2991 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 923038 T2991 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 923038 T2991 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 923038 T2991 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:41640/fm_d/pb/collection1/
[junit4:junit4] 2> 923039 T2991 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 923039 T2991 oasc.SyncStrategy.syncToMe http://127.0.0.1:41640/fm_d/pb/collection1/ has no replicas
[junit4:junit4] 2> 923039 T2991 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:41640/fm_d/pb/collection1/
[junit4:junit4] 2> 923039 T2991 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 923421 T2955 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 923427 T2974 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> 923427 T2954 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> 923427 T2990 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> 923427 T2961 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> 923451 T2991 oasc.ZkController.register We are http://127.0.0.1:41640/fm_d/pb/collection1/ and leader is http://127.0.0.1:41640/fm_d/pb/collection1/
[junit4:junit4] 2> 923452 T2991 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:41640/fm_d/pb
[junit4:junit4] 2> 923452 T2991 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 923452 T2991 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 923452 T2991 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 923454 T2991 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 923455 T2932 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 923456 T2932 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 923456 T2932 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 923537 T2932 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 923545 T2932 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:36997
[junit4:junit4] 2> 923546 T2932 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 923546 T2932 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 923546 T2932 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1371772063286
[junit4:junit4] 2> 923547 T2932 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1371772063286/solr.xml
[junit4:junit4] 2> 923547 T2932 oasc.CoreContainer.<init> New CoreContainer 1707252844
[junit4:junit4] 2> 923547 T2932 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1371772063286/'
[junit4:junit4] 2> 923547 T2932 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1371772063286/'
[junit4:junit4] 2> 923591 T2932 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 923592 T2932 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 923592 T2932 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 923592 T2932 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 923592 T2932 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 923592 T2932 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 923593 T2932 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 923593 T2932 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 923593 T2932 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 923593 T2932 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 923597 T2932 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 923597 T2932 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:54568/solr
[junit4:junit4] 2> 923597 T2932 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 923598 T2932 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 923600 T3004 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@31e48cd5 name:ZooKeeperConnection Watcher:127.0.0.1:54568 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 923600 T2932 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 923601 T2932 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 923605 T2932 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 923606 T3006 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@56064f6f name:ZooKeeperConnection Watcher:127.0.0.1:54568/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 923606 T2932 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 923609 T2932 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 924611 T2932 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:36997_fm_d%2Fpb
[junit4:junit4] 2> 924613 T2932 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:36997_fm_d%2Fpb
[junit4:junit4] 2> 924614 T2961 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> 924614 T2974 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> 924615 T2954 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 924615 T3006 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 924615 T2990 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 924615 T2954 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> 924616 T2990 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> 924616 T2961 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 924617 T2974 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 924622 T3007 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 924623 T3007 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 924931 T2955 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 924932 T2955 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:41640/fm_d/pb",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "node_name":"127.0.0.1:41640_fm_d%2Fpb"}
[junit4:junit4] 2> 924981 T2955 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "core_node_name":"4",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:36997/fm_d/pb",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "node_name":"127.0.0.1:36997_fm_d%2Fpb"}
[junit4:junit4] 2> 924982 T2955 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 924982 T2955 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 924985 T2954 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> 924985 T2990 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> 924985 T3006 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> 924985 T2961 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> 924985 T2974 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> 925624 T3007 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1371772063286/collection1
[junit4:junit4] 2> 925624 T3007 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 925625 T3007 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 925625 T3007 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 925626 T3007 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1371772063286/collection1/'
[junit4:junit4] 2> 925627 T3007 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1371772063286/collection1/lib/README' to classloader
[junit4:junit4] 2> 925627 T3007 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1371772063286/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 925660 T3007 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 925694 T3007 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 925695 T3007 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 925704 T3007 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 926038 T3007 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 926040 T3007 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 926042 T3007 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 926045 T3007 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 926058 T3007 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 926059 T3007 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1371772063286/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty3/
[junit4:junit4] 2> 926059 T3007 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4c23611e
[junit4:junit4] 2> 926059 T3007 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 926060 T3007 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty3
[junit4:junit4] 2> 926060 T3007 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty3/index/
[junit4:junit4] 2> 926060 T3007 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 926060 T3007 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty3/index
[junit4:junit4] 2> 926062 T3007 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@78b35847 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6af86332),segFN=segments_1,generation=1}
[junit4:junit4] 2> 926062 T3007 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 926064 T3007 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 926064 T3007 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 926064 T3007 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 926065 T3007 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 926065 T3007 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 926065 T3007 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 926065 T3007 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 926066 T3007 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 926066 T3007 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 926068 T3007 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 926070 T3007 oass.SolrIndexSearcher.<init> Opening Searcher@3f5914f7 main
[junit4:junit4] 2> 926070 T3007 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty3/tlog
[junit4:junit4] 2> 926071 T3007 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 926071 T3007 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 926075 T3008 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3f5914f7 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 926076 T3007 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 926077 T3007 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:36997/fm_d/pb collection:collection1 shard:shard2
[junit4:junit4] 2> 926079 T3007 oasc.ZkController.register We are http://127.0.0.1:36997/fm_d/pb/collection1/ and leader is http://127.0.0.1:34395/fm_d/pb/collection1/
[junit4:junit4] 2> 926079 T3007 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:36997/fm_d/pb
[junit4:junit4] 2> 926079 T3007 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 926079 T3007 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C1036 name=collection1 org.apache.solr.core.SolrCore@66f6043a url=http://127.0.0.1:36997/fm_d/pb/collection1 node=127.0.0.1:36997_fm_d%2Fpb C1036_STATE=coll:collection1 core:collection1 props:{collection=collection1, core=collection1, base_url=http://127.0.0.1:36997/fm_d/pb, state=down, node_name=127.0.0.1:36997_fm_d%2Fpb}
[junit4:junit4] 2> 926080 T3009 C1036 P36997 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 926080 T3007 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 926080 T3009 C1036 P36997 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 926081 T3009 C1036 P36997 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 926081 T3009 C1036 P36997 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 926081 T2932 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 926082 T2932 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 926082 T3009 C1036 P36997 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 926082 T2932 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 926086 T2968 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 4, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 926169 T2932 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 926171 T2932 oejs.AbstractConnector.doStart Started SelectChannelConnector@127.0.0.1:33717
[junit4:junit4] 2> 926174 T2932 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 926174 T2932 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 926174 T2932 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1371772065910
[junit4:junit4] 2> 926174 T2932 oasc.CoreContainer$Initializer.initialize looking for solr config file: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1371772065910/solr.xml
[junit4:junit4] 2> 926175 T2932 oasc.CoreContainer.<init> New CoreContainer 135515004
[junit4:junit4] 2> 926175 T2932 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1371772065910/'
[junit4:junit4] 2> 926175 T2932 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1371772065910/'
[junit4:junit4] 2> 926234 T2932 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 926234 T2932 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 926234 T2932 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 926234 T2932 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 926235 T2932 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 926235 T2932 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 926235 T2932 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 926235 T2932 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 926236 T2932 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 926236 T2932 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 926239 T2932 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 926240 T2932 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:54568/solr
[junit4:junit4] 2> 926240 T2932 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 926241 T2932 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 926242 T3021 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@316d717b name:ZooKeeperConnection Watcher:127.0.0.1:54568 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 926243 T2932 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 926244 T2932 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 926247 T2932 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 926248 T3023 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@40c93d55 name:ZooKeeperConnection Watcher:127.0.0.1:54568/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 926249 T2932 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 926251 T2932 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 926490 T2955 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 926491 T2955 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "core_node_name":"4",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:36997/fm_d/pb",
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "node_name":"127.0.0.1:36997_fm_d%2Fpb"}
[junit4:junit4] 2> 926495 T3006 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> 926495 T2954 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> 926495 T2974 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> 926495 T3023 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> 926495 T2990 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> 926495 T2961 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> 927087 T2968 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 4, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 927087 T2968 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={wt=javabin&coreNodeName=4&onlyIfLeader=true&checkLive=true&core=collection1&state=recovering&version=2&nodeName=127.0.0.1:36997_fm_d%252Fpb&action=PREPRECOVERY} status=0 QTime=1001
[junit4:junit4] 2> 927253 T2932 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:33717_fm_d%2Fpb
[junit4:junit4] 2> 927255 T2932 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:33717_fm_d%2Fpb
[junit4:junit4] 2> 927256 T3006 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> 927257 T2961 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> 927256 T2990 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> 927257 T3023 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 927257 T2954 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 927257 T3023 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> 927257 T2974 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 927257 T2954 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> 927258 T2974 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> 927259 T2961 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 927259 T2990 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 927259 T3006 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 927263 T3024 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 927263 T3024 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 928000 T2955 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 928000 T2955 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "core_node_name":"5",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:33717/fm_d/pb",
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "node_name":"127.0.0.1:33717_fm_d%2Fpb"}
[junit4:junit4] 2> 928001 T2955 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 928001 T2955 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 928004 T2961 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> 928004 T2974 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> 928004 T3023 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> 928004 T3006 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> 928004 T2954 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> 928004 T2990 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> 928265 T3024 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1371772065910/collection1
[junit4:junit4] 2> 928265 T3024 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 928265 T3024 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 928266 T3024 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 928266 T3024 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1371772065910/collection1/'
[junit4:junit4] 2> 928267 T3024 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1371772065910/collection1/lib/README' to classloader
[junit4:junit4] 2> 928267 T3024 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1371772065910/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 928296 T3024 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 928327 T3024 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 928328 T3024 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 928339 T3024 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 928652 T3024 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 928655 T3024 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 928656 T3024 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 928660 T3024 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 928679 T3024 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 928680 T3024 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1371772065910/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty4/
[junit4:junit4] 2> 928680 T3024 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@4c23611e
[junit4:junit4] 2> 928680 T3024 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 928681 T3024 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty4
[junit4:junit4] 2> 928681 T3024 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty4/index/
[junit4:junit4] 2> 928681 T3024 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 928682 T3024 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty4/index
[junit4:junit4] 2> 928684 T3024 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@706c8f1c lockFactory=org.apache.lucene.store.NativeFSLockFactory@59cde409),segFN=segments_1,generation=1}
[junit4:junit4] 2> 928684 T3024 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 928686 T3024 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 928686 T3024 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 928687 T3024 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 928687 T3024 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 928688 T3024 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 928688 T3024 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 928688 T3024 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 928688 T3024 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 928689 T3024 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 928690 T3024 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 928692 T3024 oass.SolrIndexSearcher.<init> Opening Searcher@7b8240bb main
[junit4:junit4] 2> 928693 T3024 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty4/tlog
[junit4:junit4] 2> 928693 T3024 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 928693 T3024 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 928697 T3025 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7b8240bb main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 928698 T3024 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 928698 T3024 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:33717/fm_d/pb collection:collection1 shard:shard1
[junit4:junit4] 2> 928701 T3024 oasc.ZkController.register We are http://127.0.0.1:33717/fm_d/pb/collection1/ and leader is http://127.0.0.1:41640/fm_d/pb/collection1/
[junit4:junit4] 2> 928701 T3024 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:33717/fm_d/pb
[junit4:junit4] 2> 928701 T3024 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 928701 T3024 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C1037 name=collection1 org.apache.solr.core.SolrCore@2a23d85e url=http://127.0.0.1:33717/fm_d/pb/collection1 node=127.0.0.1:33717_fm_d%2Fpb C1037_STATE=coll:collection1 core:collection1 props:{collection=collection1, core=collection1, base_url=http://127.0.0.1:33717/fm_d/pb, state=down, node_name=127.0.0.1:33717_fm_d%2Fpb}
[junit4:junit4] 2> 928702 T3026 C1037 P33717 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 928702 T3024 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 928702 T3026 C1037 P33717 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 928703 T3026 C1037 P33717 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 928703 T3026 C1037 P33717 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 928703 T2932 oass.SolrDispatchFilter.init user.dir=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0
[junit4:junit4] 2> 928703 T2932 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 928704 T2932 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 928705 T3026 C1037 P33717 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 928707 T2932 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 928708 T2932 oasc.AbstractFullDistribZkTestBase.waitForThingsToLevelOut Wait for recoveries to finish - wait 15 for each attempt
[junit4:junit4] 2> 928708 T2932 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):15
[junit4:junit4] 2> 928709 T2932 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 928709 T2985 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> ASYNC NEW_CORE C1038 name=collection1 org.apache.solr.core.SolrCore@66f6043a url=http://127.0.0.1:36997/fm_d/pb/collection1 node=127.0.0.1:36997_fm_d%2Fpb C1038_STATE=coll:collection1 core:collection1 props:{shard=shard2, collection=collection1, core=collection1, base_url=http://127.0.0.1:36997/fm_d/pb, state=recovering, node_name=127.0.0.1:36997_fm_d%2Fpb}
[junit4:junit4] 2> 929088 T3009 C1038 P36997 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:34395/fm_d/pb/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 929088 T3009 C1038 P36997 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:36997/fm_d/pb START replicas=[http://127.0.0.1:34395/fm_d/pb/collection1/] nUpdates=100
[junit4:junit4] 2> 929088 T3009 C1038 P36997 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 929089 T3009 C1038 P36997 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 929090 T3009 C1038 P36997 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 929090 T3009 C1038 P36997 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 929090 T3009 C1038 P36997 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 929090 T3009 C1038 P36997 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:34395/fm_d/pb/collection1/. core=collection1
[junit4:junit4] 2> 929090 T3009 C1038 P36997 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C1039 name=collection1 org.apache.solr.core.SolrCore@30a23be2 url=http://127.0.0.1:34395/fm_d/pb/collection1 node=127.0.0.1:34395_fm_d%2Fpb C1039_STATE=coll:collection1 core:collection1 props:{shard=shard2, collection=collection1, core=collection1, base_url=http://127.0.0.1:34395/fm_d/pb, state=active, node_name=127.0.0.1:34395_fm_d%2Fpb, leader=true}
[junit4:junit4] 2> 929095 T2968 C1039 P34395 oasc.SolrCore.execute [collection1] webapp=/fm_d/pb path=/get params={getVersions=100&wt=javabin&distrib=false&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 929098 T2969 C1039 P34395 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 929100 T2969 C1039 P34395 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5153b9df lockFactory=org.apache.lucene.store.NativeFSLockFactory@568f2300),segFN=segments_1,generation=1}
[junit4:junit4] 2> 929101 T2969 C1039 P34395 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 929101 T2969 C1039 P34395 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5153b9df lockFactory=org.apache.lucene.store.NativeFSLockFactory@568f2300),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5153b9df lockFactory=org.apache.lucene.store.NativeFSLockFactory@568f2300),segFN=segments_2,generation=2}
[junit4:junit4] 2> 929102 T2969 C1039 P34395 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 929102 T2969 C1039 P34395 oass.SolrIndexSearcher.<init> Opening Searcher@3bb86194 realtime
[junit4:junit4] 2> 929102 T2969 C1039 P34395 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 929102 T2969 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={commit=true&wt=javabin&commit_end_point=true&openSearcher=false&version=2&waitSearcher=true&softCommit=false} {commit=} 0 4
[junit4:junit4] 2> 929103 T3009 C1038 P36997 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 929103 T3009 C1038 P36997 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 929106 T2968 C1039 P34395 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 929106 T2968 C1039 P34395 oasc.SolrCore.execute [collection1] webapp=/fm_d/pb path=/replication params={wt=javabin&command=indexversion&qt=/replication&version=2} status=0 QTime=2
[junit4:junit4] 2> 929107 T3009 C1038 P36997 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 929107 T3009 C1038 P36997 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 929107 T3009 C1038 P36997 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 929109 T2969 C1039 P34395 oasc.SolrCore.execute [collection1] webapp=/fm_d/pb path=/replication params={wt=javabin&command=filelist&qt=/replication&version=2&generation=2} status=0 QTime=0
[junit4:junit4] 2> 929109 T3009 C1038 P36997 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 929110 T3009 C1038 P36997 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty3/index.20130620184748934
[junit4:junit4] 2> 929111 T3009 C1038 P36997 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@4b15f82c lockFactory=org.apache.lucene.store.NativeFSLockFactory@49cc9a71; maxCacheMB=0.4765625 maxMergeSizeMB=0.404296875)) fullCopy=false
[junit4:junit4] 2> 929113 T2970 C1039 P34395 oasc.SolrCore.execute [collection1] webapp=/fm_d/pb path=/replication params={wt=filestream&checksum=true&file=segments_2&command=filecontent&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 929114 T3009 C1038 P36997 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 929115 T3009 C1038 P36997 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 929116 T3009 C1038 P36997 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 929117 T3009 C1038 P36997 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@78b35847 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6af86332),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@78b35847 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6af86332),segFN=segments_2,generation=2}
[junit4:junit4] 2> 929117 T3009 C1038 P36997 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 929117 T3009 C1038 P36997 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 929117 T3009 C1038 P36997 oass.SolrIndexSearcher.<init> Opening Searcher@6230ac36 main
[junit4:junit4] 2> 929118 T3008 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6230ac36 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 929119 T3009 C1038 P36997 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty3/index.20130620184748934 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty3/index.20130620184748934;done=true>>]
[junit4:junit4] 2> 929119 T3009 C1038 P36997 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty3/index.20130620184748934
[junit4:junit4] 2> 929119 T3009 C1038 P36997 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty3/index.20130620184748934
[junit4:junit4] 2> 929119 T3009 C1038 P36997 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 929119 T3009 C1038 P36997 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 929120 T3009 C1038 P36997 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 929120 T3009 C1038 P36997 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 929121 T3009 C1038 P36997 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 929508 T2955 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 929509 T2955 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "core_node_name":"5",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:33717/fm_d/pb",
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "node_name":"127.0.0.1:33717_fm_d%2Fpb"}
[junit4:junit4] 2> 929511 T2955 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "core_node_name":"4",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:36997/fm_d/pb",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "node_name":"127.0.0.1:36997_fm_d%2Fpb"}
[junit4:junit4] 2> 929515 T2961 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> 929515 T2974 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> 929515 T2954 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> 929515 T2990 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> 929515 T3006 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> 929515 T3023 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> 929709 T2985 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 929710 T2985 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={wt=javabin&coreNodeName=5&onlyIfLeader=true&checkLive=true&core=collection1&state=recovering&version=2&nodeName=127.0.0.1:33717_fm_d%252Fpb&action=PREPRECOVERY} status=0 QTime=1001
[junit4:junit4] 2> 929710 T2932 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 930712 T2932 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> C1037_STATE=coll:collection1 core:collection1 props:{shard=shard1, collection=collection1, core=collection1, base_url=http://127.0.0.1:33717/fm_d/pb, state=recovering, node_name=127.0.0.1:33717_fm_d%2Fpb}
[junit4:junit4] 2> 931710 T3026 C1037 P33717 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:41640/fm_d/pb/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 931711 T3026 C1037 P33717 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:33717/fm_d/pb START replicas=[http://127.0.0.1:41640/fm_d/pb/collection1/] nUpdates=100
[junit4:junit4] 2> 931711 T3026 C1037 P33717 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 931712 T3026 C1037 P33717 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 931712 T3026 C1037 P33717 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 931712 T3026 C1037 P33717 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 931712 T3026 C1037 P33717 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 931712 T3026 C1037 P33717 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:41640/fm_d/pb/collection1/. core=collection1
[junit4:junit4] 2> 931712 T3026 C1037 P33717 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 931713 T2932 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> ASYNC NEW_CORE C1040 name=collection1 org.apache.solr.core.SolrCore@28b374b url=http://127.0.0.1:41640/fm_d/pb/collection1 node=127.0.0.1:41640_fm_d%2Fpb C1040_STATE=coll:collection1 core:collection1 props:{shard=shard1, collection=collection1, core=collection1, base_url=http://127.0.0.1:41640/fm_d/pb, state=active, node_name=127.0.0.1:41640_fm_d%2Fpb, leader=true}
[junit4:junit4] 2> 931716 T2984 C1040 P41640 oasc.SolrCore.execute [collection1] webapp=/fm_d/pb path=/get params={getVersions=100&wt=javabin&distrib=false&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 931718 T2983 C1040 P41640 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 931720 T2983 C1040 P41640 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3dc3c1e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2ff84037),segFN=segments_1,generation=1}
[junit4:junit4] 2> 931721 T2983 C1040 P41640 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 931722 T2983 C1040 P41640 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3dc3c1e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2ff84037),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3dc3c1e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2ff84037),segFN=segments_2,generation=2}
[junit4:junit4] 2> 931722 T2983 C1040 P41640 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 931722 T2983 C1040 P41640 oass.SolrIndexSearcher.<init> Opening Searcher@4404384 realtime
[junit4:junit4] 2> 931723 T2983 C1040 P41640 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 931723 T2983 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={commit=true&wt=javabin&commit_end_point=true&openSearcher=false&version=2&waitSearcher=true&softCommit=false} {commit=} 0 5
[junit4:junit4] 2> 931724 T3026 C1037 P33717 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 931724 T3026 C1037 P33717 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 931726 T2984 C1040 P41640 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 931726 T2984 C1040 P41640 oasc.SolrCore.execute [collection1] webapp=/fm_d/pb path=/replication params={wt=javabin&command=indexversion&qt=/replication&version=2} status=0 QTime=1
[junit4:junit4] 2> 931726 T3026 C1037 P33717 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 931727 T3026 C1037 P33717 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 931727 T3026 C1037 P33717 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 931729 T2983 C1040 P41640 oasc.SolrCore.execute [collection1] webapp=/fm_d/pb path=/replication params={wt=javabin&command=filelist&qt=/replication&version=2&generation=2} status=0 QTime=0
[junit4:junit4] 2> 931729 T3026 C1037 P33717 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 931730 T3026 C1037 P33717 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty4/index.20130620184751554
[junit4:junit4] 2> 931731 T3026 C1037 P33717 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(NRTCachingDirectory(org.apache.lucene.store.RAMDirectory@77e98085 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4714a40; maxCacheMB=0.4765625 maxMergeSizeMB=0.404296875)) fullCopy=false
[junit4:junit4] 2> 931733 T2985 C1040 P41640 oasc.SolrCore.execute [collection1] webapp=/fm_d/pb path=/replication params={wt=filestream&checksum=true&file=segments_2&command=filecontent&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 931734 T3026 C1037 P33717 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 931736 T3026 C1037 P33717 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 931736 T3026 C1037 P33717 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 931737 T3026 C1037 P33717 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@706c8f1c lockFactory=org.apache.lucene.store.NativeFSLockFactory@59cde409),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@706c8f1c lockFactory=org.apache.lucene.store.NativeFSLockFactory@59cde409),segFN=segments_2,generation=2}
[junit4:junit4] 2> 931738 T3026 C1037 P33717 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 931738 T3026 C1037 P33717 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 931738 T3026 C1037 P33717 oass.SolrIndexSearcher.<init> Opening Searcher@49bedd79 main
[junit4:junit4] 2> 931739 T3025 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@49bedd79 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 931740 T3026 C1037 P33717 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty4/index.20130620184751554 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty4/index.20130620184751554;done=true>>]
[junit4:junit4] 2> 931740 T3026 C1037 P33717 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty4/index.20130620184751554
[junit4:junit4] 2> 931740 T3026 C1037 P33717 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732/jetty4/index.20130620184751554
[junit4:junit4] 2> 931740 T3026 C1037 P33717 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 931740 T3026 C1037 P33717 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 931741 T3026 C1037 P33717 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 931741 T3026 C1037 P33717 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 931742 T3026 C1037 P33717 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 932521 T2955 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 932522 T2955 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "core_node_name":"5",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:33717/fm_d/pb",
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "node_name":"127.0.0.1:33717_fm_d%2Fpb"}
[junit4:junit4] 2> 932525 T2954 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> 932525 T2990 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> 932525 T3006 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> 932525 T2961 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> 932525 T3023 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> 932525 T2974 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> 932715 T2932 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 932715 T2932 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: collection1
[junit4:junit4] 2> ASYNC NEW_CORE C1041 name=collection1 org.apache.solr.core.SolrCore@3d92764a url=http://127.0.0.1:50852/fm_d/pb/collection1 node=127.0.0.1:50852_fm_d%2Fpb C1041_STATE=coll:control_collection core:collection1 props:{shard=shard1, collection=control_collection, core=collection1, base_url=http://127.0.0.1:50852/fm_d/pb, state=active, node_name=127.0.0.1:50852_fm_d%2Fpb, leader=true}
[junit4:junit4] 2> 932720 T2949 C1041 P50852 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 932723 T2949 C1041 P50852 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@55f0b669 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2d41f0bd),segFN=segments_1,generation=1}
[junit4:junit4] 2> 932723 T2949 C1041 P50852 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 932724 T2949 C1041 P50852 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@55f0b669 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2d41f0bd),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@55f0b669 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2d41f0bd),segFN=segments_2,generation=2}
[junit4:junit4] 2> 932724 T2949 C1041 P50852 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 932724 T2949 C1041 P50852 oass.SolrIndexSearcher.<init> Opening Searcher@91e0851 main
[junit4:junit4] 2> 932724 T2949 C1041 P50852 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 932725 T2958 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@91e0851 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 932726 T2949 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={commit=true&wt=javabin&version=2&waitSearcher=true&softCommit=false} {commit=} 0 6
[junit4:junit4] 2> C1037_STATE=coll:collection1 core:collection1 props:{shard=shard1, collection=collection1, core=collection1, base_url=http://127.0.0.1:33717/fm_d/pb, state=active, node_name=127.0.0.1:33717_fm_d%2Fpb}
[junit4:junit4] 2> 932733 T3016 C1037 P33717 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:41640/fm_d/pb/collection1/, StdNode: http://127.0.0.1:33717/fm_d/pb/collection1/, StdNode: http://127.0.0.1:34395/fm_d/pb/collection1/, StdNode: http://127.0.0.1:36997/fm_d/pb/collection1/] params:commit_end_point=true&commit=true&softCommit=false&waitSearcher=true&expungeDeletes=false
[junit4:junit4] 2> 932737 T2986 C1040 P41640 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 932737 T3017 C1037 P33717 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 932737 T2970 C1039 P34395 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 932740 T3017 C1037 P33717 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@706c8f1c lockFactory=org.apache.lucene.store.NativeFSLockFactory@59cde409),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@706c8f1c lockFactory=org.apache.lucene.store.NativeFSLockFactory@59cde409),segFN=segments_3,generation=3}
[junit4:junit4] 2> 932741 T2970 C1039 P34395 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5153b9df lockFactory=org.apache.lucene.store.NativeFSLockFactory@568f2300),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@5153b9df lockFactory=org.apache.lucene.store.NativeFSLockFactory@568f2300),segFN=segments_3,generation=3}
[junit4:junit4] 2> 932739 T2986 C1040 P41640 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3dc3c1e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2ff84037),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@3dc3c1e7 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2ff84037),segFN=segments_3,generation=3}
[junit4:junit4] 2> 932741 T2970 C1039 P34395 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 932741 T3017 C1037 P33717 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 932742 T2970 C1039 P34395 oass.SolrIndexSearcher.<init> Opening Searcher@1fe1d3b2 main
[junit4:junit4] 2> 932741 T2986 C1040 P41640 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 932742 T2970 C1039 P34395 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 932742 T3017 C1037 P33717 oass.SolrIndexSearcher.<init> Opening Searcher@4293833a main
[junit4:junit4] 2> 932743 T2986 C1040 P41640 oass.SolrIndexSearcher.<init> Opening Searcher@33811718 main
[junit4:junit4] 2> 932743 T2976 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@1fe1d3b2 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 932743 T3017 C1037 P33717 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 932744 T3025 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4293833a main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 932744 T2986 C1040 P41640 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 932744 T2992 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@33811718 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 932744 T2970 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&waitSearcher=true&softCommit=false} {commit=} 0 7
[junit4:junit4] 2> 932744 T3017 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&waitSearcher=true&softCommit=false} {commit=} 0 7
[junit4:junit4] 2> 932745 T2986 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&waitSearcher=true&softCommit=false} {commit=} 0 8
[junit4:junit4] 2> C1038_STATE=coll:collection1 core:collection1 props:{shard=shard2, collection=collection1, core=collection1, base_url=http://127.0.0.1:36997/fm_d/pb, state=active, node_name=127.0.0.1:36997_fm_d%2Fpb}
[junit4:junit4] 2> 932746 T3001 C1038 P36997 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 932747 T3001 C1038 P36997 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@78b35847 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6af86332),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@78b35847 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6af86332),segFN=segments_3,generation=3}
[junit4:junit4] 2> 932747 T3001 C1038 P36997 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 932748 T3001 C1038 P36997 oass.SolrIndexSearcher.<init> Opening Searcher@3aedfde5 main
[junit4:junit4] 2> 932749 T3001 C1038 P36997 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 932749 T3008 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3aedfde5 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 932750 T3001 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&waitSearcher=true&softCommit=false} {commit=} 0 4
[junit4:junit4] 2> 932750 T3016 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={commit=true&wt=javabin&version=2&waitSearcher=true&softCommit=false} {commit=} 0 17
[junit4:junit4] 2> 932752 T2932 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 932754 T2984 C1040 P41640 oasc.SolrCore.execute [collection1] webapp=/fm_d/pb path=/select params={tests=checkShardConsistency&wt=javabin&distrib=false&rows=0&q=*:*&version=2} hits=0 status=0 QTime=1
[junit4:junit4] 2> 932755 T3018 C1037 P33717 oasc.SolrCore.execute [collection1] webapp=/fm_d/pb path=/select params={tests=checkShardConsistency&wt=javabin&distrib=false&rows=0&q=*:*&version=2} hits=0 status=0 QTime=0
[junit4:junit4] 2> 932756 T2969 C1039 P34395 oasc.SolrCore.execute [collection1] webapp=/fm_d/pb path=/select params={tests=checkShardConsistency&wt=javabin&distrib=false&rows=0&q=*:*&version=2} hits=0 status=0 QTime=0
[junit4:junit4] 2> 932758 T2999 C1038 P36997 oasc.SolrCore.execute [collection1] webapp=/fm_d/pb path=/select params={tests=checkShardConsistency&wt=javabin&distrib=false&rows=0&q=*:*&version=2} hits=0 status=0 QTime=0
[junit4:junit4] 2> 934763 T2950 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1438407274881089536)} 0 2
[junit4:junit4] 2> 934773 T2999 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={_version_=-1438407274884235264&wt=javabin&update.distrib=FROMLEADER&version=2&update.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {deleteByQuery=*:* (-1438407274884235264)} 0 3
[junit4:junit4] 2> 934773 T3018 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={_version_=-1438407274888429568&wt=javabin&update.distrib=FROMLEADER&version=2&update.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {deleteByQuery=*:* (-1438407274888429568)} 0 1
[junit4:junit4] 2> 934774 T2984 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2} {deleteByQuery=*:* (-1438407274888429568)} 0 5
[junit4:junit4] 2> 934774 T2968 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1438407274884235264)} 0 9
[junit4:junit4] 2> 934778 T2947 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[0 (1438407274896818176)]} 0 1
[junit4:junit4] 2> 934786 T3019 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[0 (1438407274903109632)]} 0 0
[junit4:junit4] 2> 934787 T2983 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[0 (1438407274903109632)]} 0 4
[junit4:junit4] 2> 934788 T2969 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[0]} 0 7
[junit4:junit4] 2> 934791 T2948 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[1 (1438407274910449664)]} 0 1
[junit4:junit4] 2> 934798 T3017 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[1 (1438407274915692544)]} 0 1
[junit4:junit4] 2> 934798 T2986 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:36997/fm_d/pb/collection1/} {add=[1 (1438407274915692544)]} 0 3
[junit4:junit4] 2> 934799 T3001 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[1]} 0 7
[junit4:junit4] 2> 934802 T2949 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[2 (1438407274921984000)]} 0 1
[junit4:junit4] 2> 934809 T3000 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[2 (1438407274927226880)]} 0 1
[junit4:junit4] 2> 934809 T2968 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:36997/fm_d/pb/collection1/} {add=[2 (1438407274927226880)]} 0 3
[junit4:junit4] 2> 934810 T3002 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[2]} 0 6
[junit4:junit4] 2> 934812 T2950 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[3 (1438407274933518336)]} 0 0
[junit4:junit4] 2> 934817 T2999 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[3 (1438407274935615488)]} 0 0
[junit4:junit4] 2> 934818 T2969 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[3 (1438407274935615488)]} 0 4
[junit4:junit4] 2> 934820 T2947 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[4 (1438407274941906944)]} 0 0
[junit4:junit4] 2> 934826 T3016 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[4 (1438407274946101248)]} 0 0
[junit4:junit4] 2> 934826 T2984 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:36997/fm_d/pb/collection1/} {add=[4 (1438407274946101248)]} 0 2
[junit4:junit4] 2> 934827 T3001 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[4]} 0 5
[junit4:junit4] 2> 934829 T2948 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[5 (1438407274951344128)]} 0 0
[junit4:junit4] 2> 934836 T3000 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[5 (1438407274955538432)]} 0 1
[junit4:junit4] 2> 934836 T2967 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:33717/fm_d/pb/collection1/} {add=[5 (1438407274955538432)]} 0 3
[junit4:junit4] 2> 934837 T3018 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[5]} 0 6
[junit4:junit4] 2> 934839 T2949 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[6 (1438407274961829888)]} 0 0
[junit4:junit4] 2> 934844 T3002 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[6 (1438407274964975616)]} 0 1
[junit4:junit4] 2> 934844 T2970 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[6 (1438407274964975616)]} 0 3
[junit4:junit4] 2> 934845 T2983 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[6]} 0 5
[junit4:junit4] 2> 934847 T2950 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[7 (1438407274970218496)]} 0 1
[junit4:junit4] 2> 934851 T2999 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[7 (1438407274972315648)]} 0 0
[junit4:junit4] 2> 934851 T2968 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[7 (1438407274972315648)]} 0 2
[junit4:junit4] 2> 934854 T2947 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[8 (1438407274976509952)]} 0 1
[junit4:junit4] 2> 934860 T3019 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[8 (1438407274981752832)]} 0 0
[junit4:junit4] 2> 934860 T2985 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[8 (1438407274981752832)]} 0 2
[junit4:junit4] 2> 934861 T2969 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[8]} 0 5
[junit4:junit4] 2> 934863 T2948 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[9 (1438407274986995712)]} 0 0
[junit4:junit4] 2> 934869 T3001 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[9 (1438407274991190016)]} 0 0
[junit4:junit4] 2> 934870 T2967 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[9 (1438407274991190016)]} 0 3
[junit4:junit4] 2> 934870 T2986 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[9]} 0 5
[junit4:junit4] 2> 934873 T2949 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[10 (1438407274996432896)]} 0 1
[junit4:junit4] 2> 934879 T3017 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[10 (1438407275001675776)]} 0 0
[junit4:junit4] 2> 934880 T2984 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[10 (1438407275001675776)]} 0 3
[junit4:junit4] 2> 934880 T2970 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[10]} 0 5
[junit4:junit4] 2> 934882 T2950 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[11 (1438407275006918656)]} 0 0
[junit4:junit4] 2> 934888 T3016 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[11 (1438407275011112960)]} 0 0
[junit4:junit4] 2> 934888 T2983 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[11 (1438407275011112960)]} 0 2
[junit4:junit4] 2> 934889 T2968 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[11]} 0 5
[junit4:junit4] 2> 934891 T2947 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[12 (1438407275016355840)]} 0 0
[junit4:junit4] 2> 934897 T3018 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[12 (1438407275020550144)]} 0 1
[junit4:junit4] 2> 934897 T2985 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[12 (1438407275020550144)]} 0 2
[junit4:junit4] 2> 934898 T2969 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[12]} 0 5
[junit4:junit4] 2> 934900 T2948 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[13 (1438407275025793024)]} 0 0
[junit4:junit4] 2> 934904 T3019 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[13 (1438407275027890176)]} 0 0
[junit4:junit4] 2> 934905 T2986 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[13 (1438407275027890176)]} 0 3
[junit4:junit4] 2> 934907 T2949 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[14 (1438407275033133056)]} 0 0
[junit4:junit4] 2> 934912 T3017 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[14 (1438407275036278784)]} 0 0
[junit4:junit4] 2> 934912 T2984 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[14 (1438407275036278784)]} 0 2
[junit4:junit4] 2> 934915 T2950 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[15 (1438407275040473088)]} 0 1
[junit4:junit4] 2> 934921 T3016 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[15 (1438407275044667392)]} 0 1
[junit4:junit4] 2> 934922 T2983 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[15 (1438407275044667392)]} 0 4
[junit4:junit4] 2> 934922 T2967 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[15]} 0 6
[junit4:junit4] 2> 934925 T2947 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[16 (1438407275050958848)]} 0 1
[junit4:junit4] 2> 934929 T3018 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[16 (1438407275054104576)]} 0 0
[junit4:junit4] 2> 934929 T2985 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[16 (1438407275054104576)]} 0 3
[junit4:junit4] 2> 934931 T2948 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[17 (1438407275058298880)]} 0 0
[junit4:junit4] 2> 934938 T3002 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[17 (1438407275062493184)]} 0 1
[junit4:junit4] 2> 934938 T2970 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:36997/fm_d/pb/collection1/} {add=[17 (1438407275062493184)]} 0 3
[junit4:junit4] 2> 934939 T3000 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[17]} 0 6
[junit4:junit4] 2> 934941 T2949 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[18 (1438407275068784640)]} 0 0
[junit4:junit4] 2> 934948 T2999 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[18 (1438407275074027520)]} 0 0
[junit4:junit4] 2> 934948 T2968 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:33717/fm_d/pb/collection1/} {add=[18 (1438407275074027520)]} 0 2
[junit4:junit4] 2> 934949 T3019 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[18]} 0 6
[junit4:junit4] 2> 934951 T2950 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[19 (1438407275079270400)]} 0 0
[junit4:junit4] 2> 934957 T3001 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[19 (1438407275083464704)]} 0 0
[junit4:junit4] 2> 934958 T2969 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[19 (1438407275083464704)]} 0 3
[junit4:junit4] 2> 934958 T2986 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[19]} 0 5
[junit4:junit4] 2> 934960 T2947 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[20 (1438407275088707584)]} 0 0
[junit4:junit4] 2> 934966 T3017 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[20 (1438407275092901888)]} 0 0
[junit4:junit4] 2> 934967 T2984 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:36997/fm_d/pb/collection1/} {add=[20 (1438407275092901888)]} 0 3
[junit4:junit4] 2> 934967 T3002 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[20]} 0 5
[junit4:junit4] 2> 934969 T2948 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[21 (1438407275098144768)]} 0 0
[junit4:junit4] 2> 934974 T3000 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[21 (1438407275101290496)]} 0 0
[junit4:junit4] 2> 934975 T2967 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[21 (1438407275101290496)]} 0 4
[junit4:junit4] 2> 934977 T2949 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[22 (1438407275106533376)]} 0 0
[junit4:junit4] 2> 934983 T3016 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[22 (1438407275110727680)]} 0 0
[junit4:junit4] 2> 934984 T2983 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[22 (1438407275110727680)]} 0 3
[junit4:junit4] 2> 934984 T2970 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[22]} 0 5
[junit4:junit4] 2> 934987 T2950 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[23 (1438407275115970560)]} 0 1
[junit4:junit4] 2> 934993 T2999 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[23 (1438407275121213440)]} 0 1
[junit4:junit4] 2> 934993 T2968 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[23 (1438407275121213440)]} 0 3
[junit4:junit4] 2> 934994 T2985 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[23]} 0 5
[junit4:junit4] 2> 934996 T2947 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[24 (1438407275126456320)]} 0 0
[junit4:junit4] 2> 935002 T3019 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[24 (1438407275130650624)]} 0 0
[junit4:junit4] 2> 935002 T2986 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:33717/fm_d/pb/collection1/} {add=[24 (1438407275130650624)]} 0 2
[junit4:junit4] 2> 935003 T3018 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[24]} 0 5
[junit4:junit4] 2> 935005 T2948 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[25 (1438407275135893504)]} 0 0
[junit4:junit4] 2> 935011 T3001 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[25 (1438407275140087808)]} 0 0
[junit4:junit4] 2> 935012 T2969 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:33717/fm_d/pb/collection1/} {add=[25 (1438407275140087808)]} 0 3
[junit4:junit4] 2> 935012 T3017 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[25]} 0 5
[junit4:junit4] 2> 935015 T2949 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[26 (1438407275145330688)]} 0 1
[junit4:junit4] 2> 935020 T3002 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[26 (1438407275149524992)]} 0 0
[junit4:junit4] 2> 935021 T2967 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:33717/fm_d/pb/collection1/} {add=[26 (1438407275149524992)]} 0 3
[junit4:junit4] 2> 935021 T3016 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[26]} 0 4
[junit4:junit4] 2> 935024 T2950 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[27 (1438407275154767872)]} 0 1
[junit4:junit4] 2> 935029 T3019 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[27 (1438407275158962176)]} 0 0
[junit4:junit4] 2> 935030 T2984 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:36997/fm_d/pb/collection1/} {add=[27 (1438407275158962176)]} 0 3
[junit4:junit4] 2> 935030 T3000 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[27]} 0 5
[junit4:junit4] 2> 935032 T2947 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[28 (1438407275164205056)]} 0 0
[junit4:junit4] 2> 935038 T3018 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[28 (1438407275168399360)]} 0 0
[junit4:junit4] 2> 935039 T2983 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:36997/fm_d/pb/collection1/} {add=[28 (1438407275168399360)]} 0 3
[junit4:junit4] 2> 935039 T2999 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[28]} 0 5
[junit4:junit4] 2> 935042 T2948 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[29 (1438407275174690816)]} 0 0
[junit4:junit4] 2> 935049 T3001 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[29 (1438407275178885120)]} 0 1
[junit4:junit4] 2> 935049 T2970 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:33717/fm_d/pb/collection1/} {add=[29 (1438407275178885120)]} 0 3
[junit4:junit4] 2> 935050 T3017 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[29]} 0 6
[junit4:junit4] 2> 935052 T2949 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[30 (1438407275185176576)]} 0 0
[junit4:junit4] 2> 935058 T3000 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[30 (1438407275189370880)]} 0 0
[junit4:junit4] 2> 935058 T2968 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:36997/fm_d/pb/collection1/} {add=[30 (1438407275189370880)]} 0 2
[junit4:junit4] 2> 935059 T3002 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[30]} 0 5
[junit4:junit4] 2> 935061 T2950 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[31 (1438407275194613760)]} 0 0
[junit4:junit4] 2> 935067 T2999 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[31 (1438407275198808064)]} 0 0
[junit4:junit4] 2> 935068 T2969 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:33717/fm_d/pb/collection1/} {add=[31 (1438407275198808064)]} 0 3
[junit4:junit4] 2> 935068 T3016 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[31]} 0 5
[junit4:junit4] 2> 935071 T2947 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[32 (1438407275204050944)]} 0 1
[junit4:junit4] 2> 935075 T3019 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[32 (1438407275207196672)]} 0 0
[junit4:junit4] 2> 935076 T2985 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[32 (1438407275207196672)]} 0 3
[junit4:junit4] 2> 935078 T2948 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[33 (1438407275212439552)]} 0 0
[junit4:junit4] 2> 935084 T3000 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[33 (1438407275216633856)]} 0 0
[junit4:junit4] 2> 935085 T2967 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:36997/fm_d/pb/collection1/} {add=[33 (1438407275216633856)]} 0 3
[junit4:junit4] 2> 935085 T3001 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[33]} 0 5
[junit4:junit4] 2> 935087 T2949 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[34 (1438407275221876736)]} 0 0
[junit4:junit4] 2> 935092 T3018 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[34 (1438407275225022464)]} 0 1
[junit4:junit4] 2> 935092 T2986 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[34 (1438407275225022464)]} 0 3
[junit4:junit4] 2> 935094 T2950 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[35 (1438407275229216768)]} 0 0
[junit4:junit4] 2> 935101 T3017 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[35 (1438407275233411072)]} 0 1
[junit4:junit4] 2> 935101 T2984 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[35 (1438407275233411072)]} 0 3
[junit4:junit4] 2> 935102 T2970 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[35]} 0 6
[junit4:junit4] 2> 935104 T2947 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[36 (1438407275239702528)]} 0 0
[junit4:junit4] 2> 935110 T3016 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[36 (1438407275243896832)]} 0 0
[junit4:junit4] 2> 935111 T2983 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:36997/fm_d/pb/collection1/} {add=[36 (1438407275243896832)]} 0 3
[junit4:junit4] 2> 935111 T3002 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[36]} 0 5
[junit4:junit4] 2> 935114 T2948 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[37 (1438407275250188288)]} 0 1
[junit4:junit4] 2> 935120 T2999 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[37 (1438407275254382592)]} 0 0
[junit4:junit4] 2> 935121 T2968 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:33717/fm_d/pb/collection1/} {add=[37 (1438407275254382592)]} 0 3
[junit4:junit4] 2> 935121 T3019 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[37]} 0 5
[junit4:junit4] 2> 935124 T2949 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[38 (1438407275260674048)]} 0 0
[junit4:junit4] 2> 935130 T3018 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[38 (1438407275264868352)]} 0 0
[junit4:junit4] 2> 935130 T2985 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[38 (1438407275264868352)]} 0 2
[junit4:junit4] 2> 935131 T2969 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[38]} 0 5
[junit4:junit4] 2> 935133 T2950 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[39 (1438407275270111232)]} 0 0
[junit4:junit4] 2> 935139 T3000 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[39 (1438407275274305536)]} 0 0
[junit4:junit4] 2> 935140 T2967 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:33717/fm_d/pb/collection1/} {add=[39 (1438407275274305536)]} 0 3
[junit4:junit4] 2> 935140 T3017 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[39]} 0 5
[junit4:junit4] 2> 935142 T2947 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[40 (1438407275279548416)]} 0 0
[junit4:junit4] 2> 935147 T3016 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[40 (1438407275282694144)]} 0 0
[junit4:junit4] 2> 935147 T2986 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[40 (1438407275282694144)]} 0 2
[junit4:junit4] 2> 935150 T2948 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[41 (1438407275286888448)]} 0 1
[junit4:junit4] 2> 935156 T3018 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[41 (1438407275292131328)]} 0 1
[junit4:junit4] 2> 935156 T2984 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:33717/fm_d/pb/collection1/} {add=[41 (1438407275292131328)]} 0 2
[junit4:junit4] 2> 935157 T3019 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[41]} 0 5
[junit4:junit4] 2> 935159 T2949 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[42 (1438407275297374208)]} 0 0
[junit4:junit4] 2> 935165 T3018 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[42 (1438407275301568512)]} 0 0
[junit4:junit4] 2> 935166 T2985 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:33717/fm_d/pb/collection1/} {add=[42 (1438407275301568512)]} 0 3
[junit4:junit4] 2> 935166 T3017 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[42]} 0 5
[junit4:junit4] 2> 935169 T2950 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[43 (1438407275306811392)]} 0 1
[junit4:junit4] 2> 935175 T3019 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[43 (1438407275312054272)]} 0 0
[junit4:junit4] 2> 935176 T2986 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[43 (1438407275312054272)]} 0 3
[junit4:junit4] 2> 935176 T2970 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[43]} 0 5
[junit4:junit4] 2> 935179 T2948 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[44 (1438407275317297152)]} 0 1
[junit4:junit4] 2> 935183 T3018 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[44 (1438407275320442880)]} 0 0
[junit4:junit4] 2> 935184 T2983 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[44 (1438407275320442880)]} 0 3
[junit4:junit4] 2> 935186 T2949 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[45 (1438407275325685760)]} 0 0
[junit4:junit4] 2> 935190 T3001 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[45 (1438407275327782912)]} 0 0
[junit4:junit4] 2> 935191 T2969 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[45 (1438407275327782912)]} 0 3
[junit4:junit4] 2> 935193 T2947 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[46 (1438407275333025792)]} 0 0
[junit4:junit4] 2> 935200 T3016 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[46 (1438407275337220096)]} 0 1
[junit4:junit4] 2> 935200 T2984 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:33717/fm_d/pb/collection1/} {add=[46 (1438407275337220096)]} 0 3
[junit4:junit4] 2> 935201 T3017 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[46]} 0 6
[junit4:junit4] 2> 935203 T2950 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[47 (1438407275343511552)]} 0 0
[junit4:junit4] 2> 935210 T3018 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[47 (1438407275347705856)]} 0 1
[junit4:junit4] 2> 935210 T2985 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:33717/fm_d/pb/collection1/} {add=[47 (1438407275347705856)]} 0 3
[junit4:junit4] 2> 935211 T3019 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[47]} 0 6
[junit4:junit4] 2> 935213 T2948 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[48 (1438407275353997312)]} 0 0
[junit4:junit4] 2> 935219 T3016 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[48 (1438407275358191616)]} 0 0
[junit4:junit4] 2> 935220 T2986 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[48 (1438407275358191616)]} 0 3
[junit4:junit4] 2> 935221 T2967 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[48]} 0 6
[junit4:junit4] 2> 935223 T2949 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[49 (1438407275364483072)]} 0 0
[junit4:junit4] 2> 935228 T3017 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[49 (1438407275366580224)]} 0 1
[junit4:junit4] 2> 935228 T2983 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[49 (1438407275366580224)]} 0 3
[junit4:junit4] 2> 935231 T2947 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[50 (1438407275371823104)]} 0 1
[junit4:junit4] 2> 935237 T3018 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[50 (1438407275376017408)]} 0 1
[junit4:junit4] 2> 935237 T2984 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[50 (1438407275376017408)]} 0 3
[junit4:junit4] 2> 935237 T2968 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[50]} 0 4
[junit4:junit4] 2> 935240 T2950 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[51 (1438407275382308864)]} 0 1
[junit4:junit4] 2> 935246 T3019 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[51 (1438407275386503168)]} 0 0
[junit4:junit4] 2> 935247 T2985 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:36997/fm_d/pb/collection1/} {add=[51 (1438407275386503168)]} 0 3
[junit4:junit4] 2> 935247 T2999 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[51]} 0 5
[junit4:junit4] 2> 935249 T2948 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[52 (1438407275391746048)]} 0 0
[junit4:junit4] 2> 935256 T3016 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[52 (1438407275395940352)]} 0 1
[junit4:junit4] 2> 935256 T2983 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[52 (1438407275395940352)]} 0 3
[junit4:junit4] 2> 935257 T2970 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[52]} 0 6
[junit4:junit4] 2> 935259 T2949 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[53 (1438407275402231808)]} 0 0
[junit4:junit4] 2> 935265 T3002 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[53 (1438407275406426112)]} 0 0
[junit4:junit4] 2> 935266 T2969 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[53 (1438407275406426112)]} 0 3
[junit4:junit4] 2> 935266 T2984 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[53]} 0 5
[junit4:junit4] 2> 935269 T2947 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[54 (1438407275411668992)]} 0 1
[junit4:junit4] 2> 935275 T3017 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[54 (1438407275416911872)]} 0 0
[junit4:junit4] 2> 935276 T2986 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:36997/fm_d/pb/collection1/} {add=[54 (1438407275416911872)]} 0 2
[junit4:junit4] 2> 935276 T3001 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[54]} 0 5
[junit4:junit4] 2> 935278 T2950 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[55 (1438407275422154752)]} 0 0
[junit4:junit4] 2> 935285 T3018 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[55 (1438407275427397632)]} 0 1
[junit4:junit4] 2> 935285 T2985 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[55 (1438407275427397632)]} 0 2
[junit4:junit4] 2> 935286 T2967 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[55]} 0 5
[junit4:junit4] 2> 935288 T2948 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[56 (1438407275432640512)]} 0 0
[junit4:junit4] 2> 935292 T3000 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[56 (1438407275434737664)]} 0 0
[junit4:junit4] 2> 935293 T2968 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[56 (1438407275434737664)]} 0 3
[junit4:junit4] 2> 935295 T2949 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[57 (1438407275439980544)]} 0 0
[junit4:junit4] 2> 935301 T2999 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[57 (1438407275444174848)]} 0 0
[junit4:junit4] 2> 935302 T2970 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:33717/fm_d/pb/collection1/} {add=[57 (1438407275444174848)]} 0 3
[junit4:junit4] 2> 935302 T3019 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[57]} 0 5
[junit4:junit4] 2> 935305 T2947 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[58 (1438407275449417728)]} 0 1
[junit4:junit4] 2> 935311 T3001 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[58 (1438407275454660608)]} 0 0
[junit4:junit4] 2> 935312 T2969 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:36997/fm_d/pb/collection1/} {add=[58 (1438407275454660608)]} 0 3
[junit4:junit4] 2> 935312 T3002 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[58]} 0 5
[junit4:junit4] 2> 935315 T2950 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[59 (1438407275459903488)]} 0 1
[junit4:junit4] 2> 935321 T3016 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[59 (1438407275464097792)]} 0 1
[junit4:junit4] 2> 935321 T2983 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[59 (1438407275464097792)]} 0 3
[junit4:junit4] 2> 935322 T2968 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[59]} 0 5
[junit4:junit4] 2> 935324 T2948 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[60 (1438407275470389248)]} 0 0
[junit4:junit4] 2> 935330 T3000 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[60 (1438407275474583552)]} 0 0
[junit4:junit4] 2> 935331 T2970 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:33717/fm_d/pb/collection1/} {add=[60 (1438407275474583552)]} 0 3
[junit4:junit4] 2> 935331 T3017 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[60]} 0 5
[junit4:junit4] 2> 935333 T2949 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[61 (1438407275479826432)]} 0 0
[junit4:junit4] 2> 935337 T3018 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[61 (1438407275481923584)]} 0 0
[junit4:junit4] 2> 935338 T2984 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[61 (1438407275481923584)]} 0 3
[junit4:junit4] 2> 935340 T2947 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[62 (1438407275487166464)]} 0 0
[junit4:junit4] 2> 935347 T2999 C1038 P36997 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:34395/fm_d/pb/collection1/} {add=[62 (1438407275492409344)]} 0 1
[junit4:junit4] 2> 935347 T2967 C1039 P34395 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[62 (1438407275492409344)]} 0 3
[junit4:junit4] 2> 935348 T2986 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[62]} 0 5
[junit4:junit4] 2> 935350 T2950 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[63 (1438407275497652224)]} 0 0
[junit4:junit4] 2> 935356 T3016 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[63 (1438407275501846528)]} 0 0
[junit4:junit4] 2> 935357 T2985 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:33717/fm_d/pb/collection1/} {add=[63 (1438407275501846528)]} 0 3
[junit4:junit4] 2> 935357 T3019 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[63]} 0 5
[junit4:junit4] 2> 935359 T2948 C1041 P50852 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[64 (1438407275507089408)]} 0 0
[junit4:junit4] 2> 935366 T3018 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=FROMLEADER&version=2&distrib.from=http://127.0.0.1:41640/fm_d/pb/collection1/} {add=[64 (1438407275511283712)]} 0 1
[junit4:junit4] 2> 935366 T2983 C1040 P41640 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&update.distrib=TOLEADER&version=2&distrib.from=http://127.0.0.1:33717/fm_d/pb/collection1/} {add=[64 (1438407275511283712)]} 0 3
[junit4:junit4] 2> 935367 T3017 C1037 P33717 oasup.LogUpdateProcessor.finish [collection1] webapp=/fm_d/pb path=/update params={wt=javabin&version=2} {add=[64]} 0 6
[junit4:junit4] 2> 935369 T2949 C1041 P5
[...truncated too long message...]
rs=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4] 2> 1081705 T2932 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 1081705 T2932 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 1081705 T2932 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 1081706 T2932 oasc.SolrCore.closeSearcher [collection1_shard1_0_replica1] Closing main searcher on request.
[junit4:junit4] 2> 1081706 T2932 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 1081706 T2932 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1371772065910/collection1_shard1_0_replica1/data/index [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1371772065910/collection1_shard1_0_replica1/data/index;done=false>>]
[junit4:junit4] 2> 1081707 T2932 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1371772065910/collection1_shard1_0_replica1/data/index
[junit4:junit4] 2> 1081707 T2932 oasc.CachingDirectoryFactory.closeCacheValue looking to close /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1371772065910/collection1_shard1_0_replica1/data [CachedDir<<refCount=0;path=/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1371772065910/collection1_shard1_0_replica1/data;done=false>>]
[junit4:junit4] 2> 1081707 T2932 oasc.CachingDirectoryFactory.close Closing directory: /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1371772065910/collection1_shard1_0_replica1/data
[junit4:junit4] 2> 1081708 T3095 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89900453313576972-127.0.0.1:33717_fm_d%2Fpb-n_0000000004) am no longer a leader.
[junit4:junit4] 2> 1081709 T3023 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> 1081709 T3023 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 1081709 T3023 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 1081730 T2932 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/fm_d/pb,null}
[junit4:junit4] 2> 1081786 T2932 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 1081788 T2932 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:54568 54568
[junit4:junit4] 2> 1081790 T2932 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 50852
[junit4:junit4] 2> !!!! WARNING: best effort to remove /mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1371772053732 FAILED !!!!!
[junit4:junit4] 2> 1081790 T2932 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 1081790 T2932 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:54568 54568
[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=F8EA99248C2D0492 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=fr_CA -Dtests.timezone=America/Rankin_Inlet -Dtests.file.encoding=UTF-8
[junit4:junit4] ERROR 168s J0 | ChaosMonkeyShardSplitTest.testDistribSearch <<<
[junit4:junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:41640/fm_d/pb returned non ok status:500, message:Server Error
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([F8EA99248C2D0492:790C173CFB7264AE]:0)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:387)
[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:724)
[junit4:junit4] 2> 1081797 T2932 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 167896 T2931 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4:junit4] 2> NOTE: test params are: codec=Lucene41, sim=RandomSimilarityProvider(queryNorm=false,coord=no): {}, locale=fr_CA, timezone=America/Rankin_Inlet
[junit4:junit4] 2> NOTE: Linux 3.2.0-48-generic amd64/Oracle Corporation 1.8.0-ea (64-bit)/cpus=8,threads=1,free=104762488,total=336592896
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestTrie, TestPerFieldSimilarity, TestDocSet, PeerSyncTest, SliceStateUpdateTest, OverseerTest, AlternateDirectoryTest, TestSolrDeletionPolicy1, UUIDFieldTest, QueryEqualityTest, QueryParsingTest, TestFaceting, PolyFieldTest, PrimitiveFieldTypeTest, ExternalFileFieldSortTest, DocValuesTest, ResponseLogComponentTest, TestWriterPerf, TestLRUCache, AutoCommitTest, RegexBoostProcessorTest, UpdateRequestProcessorFactoryTest, TestStressRecovery, TestQueryUtils, SoftAutoCommitTest, SuggesterFSTTest, FastVectorHighlighterTest, TestMaxScoreQueryParser, SpellingQueryConverterTest, ShardSplitTest, TestFunctionQuery, SolrCoreTest, TestCharFilters, TestSolrXml, PluginInfoTest, RecoveryZkTest, TestSolrIndexConfig, TestRemoteStreaming, CoreAdminHandlerTest, SyncSliceTest, TestPluginEnable, TestCollationKeyRangeQueries, IndexSchemaTest, LegacyHTMLStripCharFilterTest, SystemInfoHandlerTest, TestBadConfig, TestRandomDVFaceting, CSVRequestHandlerTest, TestIBSimilarityFactory, BasicDistributedZkTest, FieldMutatingUpdateProcessorTest, LukeRequestHandlerTest, PrimUtilsTest, DistributedQueryElevationComponentTest, TestPropInjectDefaults, TestLMDirichletSimilarityFactory, DateFieldTest, SynonymTokenizerTest, DistributedTermsComponentTest, StatelessScriptUpdateProcessorFactoryTest, SliceStateTest, TestReloadAndDeleteDocs, BasicFunctionalityTest, TestSolrQueryParser, ShardRoutingTest, BinaryUpdateRequestHandlerTest, SchemaVersionSpecificBehaviorTest, TestLFUCache, UnloadDistributedZkTest, TestPhraseSuggestions, TestPHPSerializedResponseWriter, TestSolrQueryParserResource, TestJoin, DistributedSpellCheckComponentTest, ZkControllerTest, TestMultiCoreConfBootstrap, TestReload, TestRangeQuery, SimpleFacetsTest, SpellCheckComponentTest, SolrCmdDistributorTest, QueryElevationComponentTest, BadIndexSchemaTest, ConvertedLegacyTest, TestSort, HighlighterTest, CurrencyFieldXmlFileTest, TestCoreDiscovery, TestExtendedDismaxParser, SpellCheckCollatorTest, TestFoldingMultitermQuery, SuggesterTest, SpatialFilterTest, WordBreakSolrSpellCheckerTest, TestWordDelimiterFilterFactory, DirectUpdateHandlerOptimizeTest, SolrInfoMBeanTest, CacheHeaderTest, TestSurroundQueryParser, TestReversedWildcardFilterFactory, FileBasedSpellCheckerTest, RequestHandlersTest, TestValueSourceCache, TestIndexingPerformance, FieldAnalysisRequestHandlerTest, LoggingHandlerTest, TestJmxIntegration, JSONWriterTest, MBeansHandlerTest, JsonLoaderTest, TestBinaryResponseWriter, TestPropInject, UpdateParamsTest, CopyFieldTest, BadComponentTest, TestSolrDeletionPolicy2, TestSearchPerf, TestConfig, TestFuzzyAnalyzedSuggestions, TestPostingsSolrHighlighter, SpellPossibilityIteratorTest, TestXIncludeConfig, TestSweetSpotSimilarityFactory, TestBM25SimilarityFactory, TestFastWriter, TimeZoneUtilsTest, ResourceLoaderTest, OpenExchangeRatesOrgProviderTest, URLClassifyProcessorTest, TestFastLRUCache, DateMathParserTest, ChaosMonkeyNothingIsSafeTest, TestSolrXMLSerializer, PreAnalyzedFieldTest, TestSolrJ, TestDocumentBuilder, CircularListTest, ChaosMonkeyShardSplitTest]
[junit4:junit4] Completed on J0 in 168.42s, 1 test, 1 error <<< FAILURES!
[...truncated 10 lines...]
BUILD FAILED
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:392: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:372: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/build.xml:39: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/build.xml:181: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/solr/common-build.xml:437: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:1246: The following error occurred while executing this line:
/mnt/ssd/jenkins/workspace/Lucene-Solr-4.x-Linux/lucene/common-build.xml:890: There were test failures: 298 suites, 1255 tests, 1 error, 16 ignored (7 assumptions)
Total time: 37 minutes 34 seconds
Build step 'Invoke Ant' marked build as failure
Description set: Java: 64bit/jdk1.8.0-ea-b93 -XX:-UseCompressedOops -XX:+UseG1GC
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure