You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2013/06/11 19:27:24 UTC
[JENKINS] Lucene-Solr-Tests-4.x-Java7 - Build # 1324 - Still
Failing
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java7/1324/
1 tests failed.
FAILED: org.apache.solr.cloud.ChaosMonkeyShardSplitTest.testDistribSearch
Error Message:
Server at http://127.0.0.1:20379/fjrpo/i 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:20379/fjrpo/i returned non ok status:500, message:Server Error
at __randomizedtesting.SeedInfo.seed([7F71725B76448567:FE97FC43011BE55B]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.cloud.ShardSplitTest.splitShard(ShardSplitTest.java:228)
at org.apache.solr.cloud.ChaosMonkeyShardSplitTest.doTest(ChaosMonkeyShardSplitTest.java:136)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:601)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:722)
Build Log:
[...truncated 9602 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.ChaosMonkeyShardSplitTest
[junit4:junit4] 2> 811313 T1627 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /fjrpo/i
[junit4:junit4] 2> 811320 T1627 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./solrtest-ChaosMonkeyShardSplitTest-1370970512430
[junit4:junit4] 2> 811322 T1627 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 811322 T1628 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 811423 T1627 oasc.ZkTestServer.run start zk server on port:34285
[junit4:junit4] 2> 811424 T1627 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 811428 T1634 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4933ea4a name:ZooKeeperConnection Watcher:127.0.0.1:34285 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 811429 T1627 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 811429 T1627 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 811445 T1627 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 811447 T1636 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b020434 name:ZooKeeperConnection Watcher:127.0.0.1:34285/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 811448 T1627 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 811448 T1627 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 811458 T1627 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 811462 T1627 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 811464 T1627 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 811468 T1627 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 811469 T1627 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 811484 T1627 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 811485 T1627 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 811489 T1627 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 811490 T1627 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 811494 T1627 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 811494 T1627 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 811503 T1627 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 811503 T1627 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 811507 T1627 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 811508 T1627 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 811511 T1627 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 811512 T1627 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 811515 T1627 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 811516 T1627 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 811520 T1627 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 811520 T1627 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 811787 T1627 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 811791 T1627 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:62331
[junit4:junit4] 2> 811791 T1627 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 811792 T1627 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 811793 T1627 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370970512634
[junit4:junit4] 2> 811793 T1627 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370970512634/solr.xml
[junit4:junit4] 2> 811794 T1627 oasc.CoreContainer.<init> New CoreContainer 1469031069
[junit4:junit4] 2> 811794 T1627 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370970512634/'
[junit4:junit4] 2> 811795 T1627 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370970512634/'
[junit4:junit4] 2> 811928 T1627 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 811929 T1627 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 811929 T1627 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 811930 T1627 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 811931 T1627 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 811931 T1627 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 811932 T1627 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 811932 T1627 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 811933 T1627 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 811933 T1627 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 811951 T1627 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 811952 T1627 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:34285/solr
[junit4:junit4] 2> 811953 T1627 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 811954 T1627 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 811962 T1647 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3e49bf47 name:ZooKeeperConnection Watcher:127.0.0.1:34285 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 811962 T1627 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 811989 T1627 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 812001 T1627 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 812046 T1649 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6458f44f name:ZooKeeperConnection Watcher:127.0.0.1:34285/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 812046 T1627 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 812079 T1627 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 812131 T1627 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 812157 T1627 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 812160 T1627 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:62331_fjrpo%2Fi
[junit4:junit4] 2> 812161 T1627 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:62331_fjrpo%2Fi
[junit4:junit4] 2> 812215 T1627 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 812232 T1627 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 812235 T1627 oasc.Overseer.start Overseer (id=89847923503071235-127.0.0.1:62331_fjrpo%2Fi-n_0000000000) starting
[junit4:junit4] 2> 812246 T1627 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 812256 T1651 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 812257 T1627 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 812264 T1627 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 812266 T1627 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 812269 T1650 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 812273 T1652 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 812273 T1652 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 813773 T1650 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 813774 T1650 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:62331_fjrpo%2Fi",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:62331/fjrpo/i"}
[junit4:junit4] 2> 813774 T1650 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 813774 T1650 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 813779 T1649 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> 814277 T1652 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370970512634/collection1
[junit4:junit4] 2> 814277 T1652 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 814278 T1652 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 814278 T1652 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 814280 T1652 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370970512634/collection1/'
[junit4:junit4] 2> 814282 T1652 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370970512634/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 814282 T1652 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370970512634/collection1/lib/README' to classloader
[junit4:junit4] 2> 814337 T1652 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 814400 T1652 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 814402 T1652 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 814408 T1652 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 815006 T1652 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 815010 T1652 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 815013 T1652 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 815018 T1652 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 815045 T1652 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 815045 T1652 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370970512634/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/control/data/
[junit4:junit4] 2> 815045 T1652 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@86b4507
[junit4:junit4] 2> 815046 T1652 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 815046 T1652 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/control/data
[junit4:junit4] 2> 815047 T1652 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/control/data/index/
[junit4:junit4] 2> 815047 T1652 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 815047 T1652 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/control/data/index
[junit4:junit4] 2> 815052 T1652 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2401ca0c lockFactory=org.apache.lucene.store.NativeFSLockFactory@430d56e3),segFN=segments_1,generation=1}
[junit4:junit4] 2> 815052 T1652 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 815055 T1652 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 815056 T1652 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 815056 T1652 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 815057 T1652 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 815057 T1652 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 815058 T1652 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 815058 T1652 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 815059 T1652 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 815059 T1652 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 815074 T1652 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 815081 T1652 oass.SolrIndexSearcher.<init> Opening Searcher@4843db2d main
[junit4:junit4] 2> 815081 T1652 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/control/data/tlog
[junit4:junit4] 2> 815082 T1652 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 815083 T1652 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 815086 T1653 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4843db2d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 815088 T1652 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 815088 T1652 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:62331/fjrpo/i collection:control_collection shard:shard1
[junit4:junit4] 2> 815089 T1652 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 815109 T1652 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 815112 T1652 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 815112 T1652 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 815113 T1652 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:62331/fjrpo/i/collection1/
[junit4:junit4] 2> 815113 T1652 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 815113 T1652 oasc.SyncStrategy.syncToMe http://127.0.0.1:62331/fjrpo/i/collection1/ has no replicas
[junit4:junit4] 2> 815114 T1652 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:62331/fjrpo/i/collection1/
[junit4:junit4] 2> 815114 T1652 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 815297 T1650 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 815316 T1649 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> 815334 T1652 oasc.ZkController.register We are http://127.0.0.1:62331/fjrpo/i/collection1/ and leader is http://127.0.0.1:62331/fjrpo/i/collection1/
[junit4:junit4] 2> 815334 T1652 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:62331/fjrpo/i
[junit4:junit4] 2> 815334 T1652 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 815334 T1652 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 815335 T1652 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 815336 T1652 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 815338 T1627 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1
[junit4:junit4] 2> 815338 T1627 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 815339 T1627 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 815357 T1627 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 815359 T1627 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 815361 T1656 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@47eac3e3 name:ZooKeeperConnection Watcher:127.0.0.1:34285/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 815361 T1627 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 815362 T1627 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 815365 T1627 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 815612 T1627 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 815616 T1627 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:20379
[junit4:junit4] 2> 815617 T1627 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 815617 T1627 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 815618 T1627 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370970516474
[junit4:junit4] 2> 815618 T1627 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370970516474/solr.xml
[junit4:junit4] 2> 815619 T1627 oasc.CoreContainer.<init> New CoreContainer 115163262
[junit4:junit4] 2> 815619 T1627 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370970516474/'
[junit4:junit4] 2> 815620 T1627 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370970516474/'
[junit4:junit4] 2> 815741 T1627 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 815742 T1627 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 815743 T1627 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 815743 T1627 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 815744 T1627 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 815744 T1627 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 815745 T1627 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 815745 T1627 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 815746 T1627 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 815746 T1627 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 815763 T1627 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 815764 T1627 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:34285/solr
[junit4:junit4] 2> 815764 T1627 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 815765 T1627 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 815768 T1667 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6889af5b name:ZooKeeperConnection Watcher:127.0.0.1:34285 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 815769 T1627 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 815782 T1627 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 815795 T1627 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 815797 T1669 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@76c74f72 name:ZooKeeperConnection Watcher:127.0.0.1:34285/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 815797 T1627 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 815809 T1627 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 816813 T1627 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:20379_fjrpo%2Fi
[junit4:junit4] 2> 816816 T1627 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:20379_fjrpo%2Fi
[junit4:junit4] 2> 816818 T1649 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> 816820 T1656 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 816820 T1669 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 816821 T1649 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 816831 T1650 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 816832 T1650 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:62331_fjrpo%2Fi",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:62331/fjrpo/i"}
[junit4:junit4] 2> 816835 T1670 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 816836 T1670 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 816846 T1649 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> 816846 T1656 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> 816846 T1669 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> 818358 T1650 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 818359 T1650 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:20379_fjrpo%2Fi",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:20379/fjrpo/i"}
[junit4:junit4] 2> 818359 T1650 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 818359 T1650 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 818384 T1649 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> 818385 T1656 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> 818385 T1669 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> 818839 T1670 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370970516474/collection1
[junit4:junit4] 2> 818839 T1670 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 818840 T1670 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 818840 T1670 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 818842 T1670 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370970516474/collection1/'
[junit4:junit4] 2> 818843 T1670 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370970516474/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 818844 T1670 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370970516474/collection1/lib/README' to classloader
[junit4:junit4] 2> 818898 T1670 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 818960 T1670 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 818962 T1670 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 818968 T1670 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 819556 T1670 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 819560 T1670 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 819562 T1670 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 819568 T1670 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 819594 T1670 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 819595 T1670 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370970516474/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty1/
[junit4:junit4] 2> 819595 T1670 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@86b4507
[junit4:junit4] 2> 819596 T1670 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 819596 T1670 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty1
[junit4:junit4] 2> 819597 T1670 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty1/index/
[junit4:junit4] 2> 819597 T1670 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 819598 T1670 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty1/index
[junit4:junit4] 2> 819601 T1670 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@358fba1e lockFactory=org.apache.lucene.store.NativeFSLockFactory@6bcb92d4),segFN=segments_1,generation=1}
[junit4:junit4] 2> 819602 T1670 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 819605 T1670 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 819605 T1670 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 819606 T1670 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 819607 T1670 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 819608 T1670 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 819608 T1670 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 819608 T1670 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 819609 T1670 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 819610 T1670 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 819626 T1670 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 819633 T1670 oass.SolrIndexSearcher.<init> Opening Searcher@3f74259b main
[junit4:junit4] 2> 819634 T1670 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty1/tlog
[junit4:junit4] 2> 819635 T1670 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 819635 T1670 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 819640 T1671 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3f74259b main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 819642 T1670 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 819643 T1670 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:20379/fjrpo/i collection:collection1 shard:shard1
[junit4:junit4] 2> 819644 T1670 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 819669 T1670 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 819680 T1670 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 819680 T1670 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 819681 T1670 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:20379/fjrpo/i/collection1/
[junit4:junit4] 2> 819681 T1670 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 819681 T1670 oasc.SyncStrategy.syncToMe http://127.0.0.1:20379/fjrpo/i/collection1/ has no replicas
[junit4:junit4] 2> 819681 T1670 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:20379/fjrpo/i/collection1/
[junit4:junit4] 2> 819682 T1670 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 819889 T1650 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 819909 T1649 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> 819909 T1656 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> 819909 T1669 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> 819949 T1670 oasc.ZkController.register We are http://127.0.0.1:20379/fjrpo/i/collection1/ and leader is http://127.0.0.1:20379/fjrpo/i/collection1/
[junit4:junit4] 2> 819949 T1670 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:20379/fjrpo/i
[junit4:junit4] 2> 819949 T1670 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 819949 T1670 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 819950 T1670 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 819952 T1670 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 819953 T1627 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1
[junit4:junit4] 2> 819954 T1627 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 819954 T1627 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 820239 T1627 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 820242 T1627 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:61466
[junit4:junit4] 2> 820243 T1627 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 820244 T1627 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 820244 T1627 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370970521079
[junit4:junit4] 2> 820245 T1627 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370970521079/solr.xml
[junit4:junit4] 2> 820245 T1627 oasc.CoreContainer.<init> New CoreContainer 868971943
[junit4:junit4] 2> 820246 T1627 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370970521079/'
[junit4:junit4] 2> 820247 T1627 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370970521079/'
[junit4:junit4] 2> 820376 T1627 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 820377 T1627 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 820377 T1627 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 820378 T1627 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 820378 T1627 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 820379 T1627 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 820379 T1627 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 820380 T1627 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 820380 T1627 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 820381 T1627 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 820397 T1627 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 820398 T1627 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:34285/solr
[junit4:junit4] 2> 820398 T1627 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 820399 T1627 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 820402 T1683 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@54b40f0b name:ZooKeeperConnection Watcher:127.0.0.1:34285 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 820403 T1627 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 820417 T1627 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 820427 T1627 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 820429 T1685 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3a455837 name:ZooKeeperConnection Watcher:127.0.0.1:34285/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 820429 T1627 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 820441 T1627 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 821424 T1650 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 821425 T1650 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:20379_fjrpo%2Fi",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:20379/fjrpo/i"}
[junit4:junit4] 2> 821441 T1649 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> 821441 T1656 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> 821441 T1685 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> 821441 T1669 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> 821445 T1627 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:61466_fjrpo%2Fi
[junit4:junit4] 2> 821447 T1627 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:61466_fjrpo%2Fi
[junit4:junit4] 2> 821454 T1649 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> 821454 T1656 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> 821454 T1669 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> 821454 T1685 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> 821456 T1649 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 821456 T1656 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 821457 T1669 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 821457 T1685 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 821462 T1686 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 821463 T1686 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 822948 T1650 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 822949 T1650 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:61466_fjrpo%2Fi",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:61466/fjrpo/i"}
[junit4:junit4] 2> 822949 T1650 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 822949 T1650 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 822971 T1649 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> 822971 T1656 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> 822971 T1669 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> 822971 T1685 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> 823466 T1686 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370970521079/collection1
[junit4:junit4] 2> 823466 T1686 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 823467 T1686 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 823467 T1686 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 823469 T1686 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370970521079/collection1/'
[junit4:junit4] 2> 823470 T1686 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370970521079/collection1/lib/README' to classloader
[junit4:junit4] 2> 823471 T1686 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370970521079/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 823525 T1686 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 823585 T1686 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 823587 T1686 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 823593 T1686 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 824114 T1686 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 824117 T1686 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 824118 T1686 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 824122 T1686 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 824145 T1686 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 824146 T1686 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370970521079/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty2/
[junit4:junit4] 2> 824146 T1686 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@86b4507
[junit4:junit4] 2> 824146 T1686 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 824147 T1686 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty2
[junit4:junit4] 2> 824147 T1686 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty2/index/
[junit4:junit4] 2> 824147 T1686 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 824148 T1686 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty2/index
[junit4:junit4] 2> 824151 T1686 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6ec3bd4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@603842a9),segFN=segments_1,generation=1}
[junit4:junit4] 2> 824151 T1686 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 824154 T1686 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 824154 T1686 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 824154 T1686 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 824155 T1686 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 824155 T1686 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 824156 T1686 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 824156 T1686 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 824156 T1686 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 824157 T1686 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 824167 T1686 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 824172 T1686 oass.SolrIndexSearcher.<init> Opening Searcher@72a18b56 main
[junit4:junit4] 2> 824172 T1686 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty2/tlog
[junit4:junit4] 2> 824173 T1686 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 824173 T1686 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 824177 T1687 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@72a18b56 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 824178 T1686 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 824178 T1686 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:61466/fjrpo/i collection:collection1 shard:shard2
[junit4:junit4] 2> 824179 T1686 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 824200 T1686 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 824209 T1686 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 824209 T1686 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 824209 T1686 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:61466/fjrpo/i/collection1/
[junit4:junit4] 2> 824209 T1686 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 824210 T1686 oasc.SyncStrategy.syncToMe http://127.0.0.1:61466/fjrpo/i/collection1/ has no replicas
[junit4:junit4] 2> 824210 T1686 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:61466/fjrpo/i/collection1/
[junit4:junit4] 2> 824210 T1686 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 824476 T1650 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 824494 T1649 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> 824494 T1685 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> 824494 T1656 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> 824494 T1669 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> 824530 T1686 oasc.ZkController.register We are http://127.0.0.1:61466/fjrpo/i/collection1/ and leader is http://127.0.0.1:61466/fjrpo/i/collection1/
[junit4:junit4] 2> 824530 T1686 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:61466/fjrpo/i
[junit4:junit4] 2> 824530 T1686 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 824530 T1686 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 824530 T1686 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 824532 T1686 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 824533 T1627 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1
[junit4:junit4] 2> 824534 T1627 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 824535 T1627 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 824815 T1627 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 824818 T1627 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:42284
[junit4:junit4] 2> 824819 T1627 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 824820 T1627 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 824820 T1627 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370970525662
[junit4:junit4] 2> 824821 T1627 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370970525662/solr.xml
[junit4:junit4] 2> 824821 T1627 oasc.CoreContainer.<init> New CoreContainer 1557241937
[junit4:junit4] 2> 824822 T1627 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370970525662/'
[junit4:junit4] 2> 824823 T1627 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370970525662/'
[junit4:junit4] 2> 824951 T1627 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 824952 T1627 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 824953 T1627 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 824953 T1627 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 824954 T1627 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 824954 T1627 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 824955 T1627 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 824955 T1627 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 824956 T1627 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 824956 T1627 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 824974 T1627 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 824975 T1627 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:34285/solr
[junit4:junit4] 2> 824975 T1627 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 824977 T1627 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 824980 T1699 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2718cbbe name:ZooKeeperConnection Watcher:127.0.0.1:34285 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 824980 T1627 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 824996 T1627 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 825005 T1627 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 825007 T1701 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5f042dad name:ZooKeeperConnection Watcher:127.0.0.1:34285/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 825007 T1627 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 825016 T1627 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 826001 T1650 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 826002 T1650 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:61466_fjrpo%2Fi",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:61466/fjrpo/i"}
[junit4:junit4] 2> 826018 T1656 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> 826018 T1685 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> 826018 T1701 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> 826018 T1669 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> 826018 T1649 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> 826020 T1627 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42284_fjrpo%2Fi
[junit4:junit4] 2> 826027 T1627 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42284_fjrpo%2Fi
[junit4:junit4] 2> 826029 T1656 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> 826029 T1685 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> 826029 T1669 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> 826029 T1649 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> 826030 T1701 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 826030 T1701 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> 826031 T1656 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 826031 T1685 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 826033 T1669 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 826033 T1649 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 826038 T1702 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 826038 T1702 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 827530 T1650 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 827531 T1650 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"4",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42284_fjrpo%2Fi",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42284/fjrpo/i"}
[junit4:junit4] 2> 827531 T1650 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 827531 T1650 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 827578 T1669 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> 827578 T1649 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> 827578 T1656 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> 827578 T1701 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> 827578 T1685 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> 828042 T1702 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370970525662/collection1
[junit4:junit4] 2> 828042 T1702 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 828043 T1702 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 828043 T1702 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 828045 T1702 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370970525662/collection1/'
[junit4:junit4] 2> 828046 T1702 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370970525662/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 828047 T1702 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370970525662/collection1/lib/README' to classloader
[junit4:junit4] 2> 828100 T1702 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 828161 T1702 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 828163 T1702 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 828169 T1702 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 828734 T1702 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 828738 T1702 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 828740 T1702 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 828746 T1702 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 828771 T1702 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 828771 T1702 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370970525662/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty3/
[junit4:junit4] 2> 828772 T1702 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@86b4507
[junit4:junit4] 2> 828772 T1702 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 828774 T1702 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty3
[junit4:junit4] 2> 828774 T1702 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty3/index/
[junit4:junit4] 2> 828774 T1702 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 828775 T1702 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty3/index
[junit4:junit4] 2> 828778 T1702 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@398b50e9 lockFactory=org.apache.lucene.store.NativeFSLockFactory@437e3112),segFN=segments_1,generation=1}
[junit4:junit4] 2> 828779 T1702 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 828782 T1702 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 828782 T1702 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 828783 T1702 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 828784 T1702 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 828784 T1702 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 828785 T1702 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 828785 T1702 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 828786 T1702 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 828786 T1702 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 828801 T1702 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 828808 T1702 oass.SolrIndexSearcher.<init> Opening Searcher@48dfaa07 main
[junit4:junit4] 2> 828808 T1702 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty3/tlog
[junit4:junit4] 2> 828809 T1702 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 828810 T1702 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 828814 T1703 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@48dfaa07 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 828817 T1702 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 828817 T1702 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:42284/fjrpo/i collection:collection1 shard:shard1
[junit4:junit4] 2> 828821 T1702 oasc.ZkController.register We are http://127.0.0.1:42284/fjrpo/i/collection1/ and leader is http://127.0.0.1:20379/fjrpo/i/collection1/
[junit4:junit4] 2> 828821 T1702 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:42284/fjrpo/i
[junit4:junit4] 2> 828821 T1702 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 828821 T1702 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C625 name=collection1 org.apache.solr.core.SolrCore@6915cd06 url=http://127.0.0.1:42284/fjrpo/i/collection1 node=127.0.0.1:42284_fjrpo%2Fi C625_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:42284_fjrpo%2Fi, base_url=http://127.0.0.1:42284/fjrpo/i}
[junit4:junit4] 2> 828822 T1704 C625 P42284 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 828822 T1702 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 828822 T1704 C625 P42284 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 828823 T1704 C625 P42284 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 828823 T1704 C625 P42284 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 828824 T1627 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1
[junit4:junit4] 2> 828824 T1627 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 828825 T1704 C625 P42284 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 828825 T1627 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 828852 T1659 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 4, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 829084 T1650 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 829085 T1650 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"4",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42284_fjrpo%2Fi",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42284/fjrpo/i"}
[junit4:junit4] 2> 829101 T1627 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 829103 T1669 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> 829103 T1701 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> 829103 T1685 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> 829103 T1649 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> 829103 T1656 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> 829104 T1627 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:20667
[junit4:junit4] 2> 829106 T1627 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 829106 T1627 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 829107 T1627 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370970529959
[junit4:junit4] 2> 829107 T1627 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370970529959/solr.xml
[junit4:junit4] 2> 829108 T1627 oasc.CoreContainer.<init> New CoreContainer 745447670
[junit4:junit4] 2> 829109 T1627 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370970529959/'
[junit4:junit4] 2> 829109 T1627 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370970529959/'
[junit4:junit4] 2> 829231 T1627 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 829232 T1627 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 829233 T1627 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 829233 T1627 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 829233 T1627 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 829234 T1627 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 829234 T1627 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 829235 T1627 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 829235 T1627 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 829236 T1627 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 829253 T1627 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 829253 T1627 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:34285/solr
[junit4:junit4] 2> 829254 T1627 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 829255 T1627 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 829259 T1716 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9f61573 name:ZooKeeperConnection Watcher:127.0.0.1:34285 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 829259 T1627 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 829261 T1627 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 829273 T1627 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 829275 T1718 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@658cfaa9 name:ZooKeeperConnection Watcher:127.0.0.1:34285/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 829276 T1627 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 829288 T1627 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 829853 T1659 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 4, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 829853 T1659 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=4&state=recovering&nodeName=127.0.0.1:42284_fjrpo%252Fi&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1001
[junit4:junit4] 2> 830291 T1627 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:20667_fjrpo%2Fi
[junit4:junit4] 2> 830294 T1627 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:20667_fjrpo%2Fi
[junit4:junit4] 2> 830296 T1669 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> 830296 T1656 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> 830296 T1649 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> 830298 T1701 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 830298 T1718 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 830298 T1685 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> 830299 T1701 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> 830299 T1669 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 830300 T1656 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 830306 T1649 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 830307 T1685 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 830312 T1719 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 830312 T1719 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 830609 T1650 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 830610 T1650 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"5",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:20667_fjrpo%2Fi",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:20667/fjrpo/i"}
[junit4:junit4] 2> 830611 T1650 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 830611 T1650 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 830649 T1656 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> 830649 T1669 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> 830649 T1718 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> 830649 T1701 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> 830649 T1649 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> 830649 T1685 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> 831315 T1719 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370970529959/collection1
[junit4:junit4] 2> 831315 T1719 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 831316 T1719 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 831316 T1719 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 831318 T1719 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370970529959/collection1/'
[junit4:junit4] 2> 831320 T1719 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370970529959/collection1/lib/README' to classloader
[junit4:junit4] 2> 831320 T1719 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370970529959/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 831373 T1719 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 831434 T1719 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 831436 T1719 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 831442 T1719 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> ASYNC NEW_CORE C626 name=collection1 org.apache.solr.core.SolrCore@6915cd06 url=http://127.0.0.1:42284/fjrpo/i/collection1 node=127.0.0.1:42284_fjrpo%2Fi C626_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:42284_fjrpo%2Fi, base_url=http://127.0.0.1:42284/fjrpo/i}
[junit4:junit4] 2> 831871 T1704 C626 P42284 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:20379/fjrpo/i/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 831872 T1704 C626 P42284 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:42284/fjrpo/i START replicas=[http://127.0.0.1:20379/fjrpo/i/collection1/] nUpdates=100
[junit4:junit4] 2> 831872 T1704 C626 P42284 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 831873 T1704 C626 P42284 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 831873 T1704 C626 P42284 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 831873 T1704 C626 P42284 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 831873 T1704 C626 P42284 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 831874 T1704 C626 P42284 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:20379/fjrpo/i/collection1/. core=collection1
[junit4:junit4] 2> 831874 T1704 C626 P42284 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C627 name=collection1 org.apache.solr.core.SolrCore@77341934 url=http://127.0.0.1:20379/fjrpo/i/collection1 node=127.0.0.1:20379_fjrpo%2Fi C627_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:20379_fjrpo%2Fi, base_url=http://127.0.0.1:20379/fjrpo/i, leader=true}
[junit4:junit4] 2> 831882 T1660 C627 P20379 oasc.SolrCore.execute [collection1] webapp=/fjrpo/i path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 831886 T1661 C627 P20379 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 831888 T1661 C627 P20379 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@358fba1e lockFactory=org.apache.lucene.store.NativeFSLockFactory@6bcb92d4),segFN=segments_1,generation=1}
[junit4:junit4] 2> 831889 T1661 C627 P20379 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 831890 T1661 C627 P20379 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@358fba1e lockFactory=org.apache.lucene.store.NativeFSLockFactory@6bcb92d4),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@358fba1e lockFactory=org.apache.lucene.store.NativeFSLockFactory@6bcb92d4),segFN=segments_2,generation=2}
[junit4:junit4] 2> 831890 T1661 C627 P20379 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 831891 T1661 C627 P20379 oass.SolrIndexSearcher.<init> Opening Searcher@42a050fd realtime
[junit4:junit4] 2> 831891 T1661 C627 P20379 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 831892 T1661 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 6
[junit4:junit4] 2> 831893 T1704 C626 P42284 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 831893 T1704 C626 P42284 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 831895 T1662 C627 P20379 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 831895 T1662 C627 P20379 oasc.SolrCore.execute [collection1] webapp=/fjrpo/i path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> 831896 T1704 C626 P42284 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 831896 T1704 C626 P42284 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 831897 T1704 C626 P42284 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 831899 T1662 C627 P20379 oasc.SolrCore.execute [collection1] webapp=/fjrpo/i path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=0
[junit4:junit4] 2> 831900 T1704 C626 P42284 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 831901 T1704 C626 P42284 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty3/index.20130611130853009
[junit4:junit4] 2> 831901 T1704 C626 P42284 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@3b917034 lockFactory=org.apache.lucene.store.NativeFSLockFactory@17d99a9a) fullCopy=false
[junit4:junit4] 2> 831904 T1662 C627 P20379 oasc.SolrCore.execute [collection1] webapp=/fjrpo/i path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 831905 T1704 C626 P42284 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 831907 T1704 C626 P42284 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 831907 T1704 C626 P42284 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 831909 T1704 C626 P42284 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@398b50e9 lockFactory=org.apache.lucene.store.NativeFSLockFactory@437e3112),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@398b50e9 lockFactory=org.apache.lucene.store.NativeFSLockFactory@437e3112),segFN=segments_2,generation=2}
[junit4:junit4] 2> 831910 T1704 C626 P42284 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 831910 T1704 C626 P42284 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 831910 T1704 C626 P42284 oass.SolrIndexSearcher.<init> Opening Searcher@658af38b main
[junit4:junit4] 2> 831912 T1703 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@658af38b main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 831912 T1704 C626 P42284 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty3/index.20130611130853009 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty3/index.20130611130853009;done=true>>]
[junit4:junit4] 2> 831913 T1704 C626 P42284 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty3/index.20130611130853009
[junit4:junit4] 2> 831913 T1704 C626 P42284 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty3/index.20130611130853009
[junit4:junit4] 2> 831913 T1704 C626 P42284 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 831913 T1704 C626 P42284 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 831914 T1704 C626 P42284 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 831914 T1704 C626 P42284 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 831920 T1704 C626 P42284 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 832027 T1719 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 832032 T1719 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 832034 T1719 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 832039 T1719 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 832065 T1719 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 832066 T1719 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370970529959/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty4/
[junit4:junit4] 2> 832066 T1719 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@86b4507
[junit4:junit4] 2> 832067 T1719 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 832067 T1719 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty4
[junit4:junit4] 2> 832068 T1719 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty4/index/
[junit4:junit4] 2> 832068 T1719 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 832069 T1719 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty4/index
[junit4:junit4] 2> 832072 T1719 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@39ff894b lockFactory=org.apache.lucene.store.NativeFSLockFactory@4a49a533),segFN=segments_1,generation=1}
[junit4:junit4] 2> 832073 T1719 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 832076 T1719 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 832077 T1719 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 832077 T1719 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 832078 T1719 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 832079 T1719 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 832079 T1719 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 832080 T1719 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 832081 T1719 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 832081 T1719 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 832098 T1719 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 832105 T1719 oass.SolrIndexSearcher.<init> Opening Searcher@56d498f8 main
[junit4:junit4] 2> 832106 T1719 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty4/tlog
[junit4:junit4] 2> 832107 T1719 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 832107 T1719 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 832112 T1722 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@56d498f8 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 832114 T1719 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 832114 T1719 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:20667/fjrpo/i collection:collection1 shard:shard2
[junit4:junit4] 2> 832118 T1719 oasc.ZkController.register We are http://127.0.0.1:20667/fjrpo/i/collection1/ and leader is http://127.0.0.1:61466/fjrpo/i/collection1/
[junit4:junit4] 2> 832119 T1719 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:20667/fjrpo/i
[junit4:junit4] 2> 832119 T1719 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 832119 T1719 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C628 name=collection1 org.apache.solr.core.SolrCore@668a155d url=http://127.0.0.1:20667/fjrpo/i/collection1 node=127.0.0.1:20667_fjrpo%2Fi C628_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:20667_fjrpo%2Fi, base_url=http://127.0.0.1:20667/fjrpo/i}
[junit4:junit4] 2> 832120 T1723 C628 P20667 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 832120 T1723 C628 P20667 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 832120 T1719 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 832120 T1723 C628 P20667 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 832121 T1723 C628 P20667 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 832122 T1627 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1
[junit4:junit4] 2> 832122 T1627 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 832123 T1627 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 832179 T1627 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 832179 T1723 C628 P20667 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 832180 T1627 oasc.AbstractFullDistribZkTestBase.waitForThingsToLevelOut Wait for recoveries to finish - wait 15 for each attempt
[junit4:junit4] 2> 832181 T1650 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 832181 T1627 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):15
[junit4:junit4] 2> 832182 T1650 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"4",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42284_fjrpo%2Fi",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42284/fjrpo/i"}
[junit4:junit4] 2> 832182 T1627 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 832186 T1650 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"5",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:20667_fjrpo%2Fi",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:20667/fjrpo/i"}
[junit4:junit4] 2> 832192 T1675 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 832229 T1656 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> 832229 T1718 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> 832229 T1701 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> 832229 T1685 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> 832229 T1669 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> 832229 T1649 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> 833184 T1627 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 833194 T1675 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 833194 T1675 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=5&state=recovering&nodeName=127.0.0.1:20667_fjrpo%252Fi&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1002
[junit4:junit4] 2> 834187 T1627 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 835190 T1627 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> C628_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:20667_fjrpo%2Fi, base_url=http://127.0.0.1:20667/fjrpo/i}
[junit4:junit4] 2> 835196 T1723 C628 P20667 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:61466/fjrpo/i/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 835196 T1723 C628 P20667 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:20667/fjrpo/i START replicas=[http://127.0.0.1:61466/fjrpo/i/collection1/] nUpdates=100
[junit4:junit4] 2> 835197 T1723 C628 P20667 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 835197 T1723 C628 P20667 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 835197 T1723 C628 P20667 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 835197 T1723 C628 P20667 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 835197 T1723 C628 P20667 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 835198 T1723 C628 P20667 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:61466/fjrpo/i/collection1/. core=collection1
[junit4:junit4] 2> 835199 T1723 C628 P20667 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C629 name=collection1 org.apache.solr.core.SolrCore@283caa4 url=http://127.0.0.1:61466/fjrpo/i/collection1 node=127.0.0.1:61466_fjrpo%2Fi C629_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:61466_fjrpo%2Fi, base_url=http://127.0.0.1:61466/fjrpo/i, leader=true}
[junit4:junit4] 2> 835207 T1676 C629 P61466 oasc.SolrCore.execute [collection1] webapp=/fjrpo/i path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 2> 835211 T1677 C629 P61466 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 835214 T1677 C629 P61466 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6ec3bd4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@603842a9),segFN=segments_1,generation=1}
[junit4:junit4] 2> 835215 T1677 C629 P61466 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 835216 T1677 C629 P61466 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6ec3bd4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@603842a9),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6ec3bd4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@603842a9),segFN=segments_2,generation=2}
[junit4:junit4] 2> 835216 T1677 C629 P61466 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 835217 T1677 C629 P61466 oass.SolrIndexSearcher.<init> Opening Searcher@417dced realtime
[junit4:junit4] 2> 835217 T1677 C629 P61466 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 835218 T1677 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 7
[junit4:junit4] 2> 835219 T1723 C628 P20667 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 835219 T1723 C628 P20667 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 835221 T1678 C629 P61466 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 835221 T1678 C629 P61466 oasc.SolrCore.execute [collection1] webapp=/fjrpo/i path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> 835222 T1723 C628 P20667 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 835222 T1723 C628 P20667 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 835222 T1723 C628 P20667 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 835225 T1678 C629 P61466 oasc.SolrCore.execute [collection1] webapp=/fjrpo/i path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=0
[junit4:junit4] 2> 835226 T1723 C628 P20667 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 835227 T1723 C628 P20667 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty4/index.20130611130856335
[junit4:junit4] 2> 835227 T1723 C628 P20667 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@f8029d3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@51489563) fullCopy=false
[junit4:junit4] 2> 835230 T1678 C629 P61466 oasc.SolrCore.execute [collection1] webapp=/fjrpo/i path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 835231 T1723 C628 P20667 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 835232 T1723 C628 P20667 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 835233 T1723 C628 P20667 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 835234 T1723 C628 P20667 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@39ff894b lockFactory=org.apache.lucene.store.NativeFSLockFactory@4a49a533),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@39ff894b lockFactory=org.apache.lucene.store.NativeFSLockFactory@4a49a533),segFN=segments_2,generation=2}
[junit4:junit4] 2> 835235 T1723 C628 P20667 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 835235 T1723 C628 P20667 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 835235 T1723 C628 P20667 oass.SolrIndexSearcher.<init> Opening Searcher@3df3e636 main
[junit4:junit4] 2> 835237 T1722 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3df3e636 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 835237 T1723 C628 P20667 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty4/index.20130611130856335 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty4/index.20130611130856335;done=true>>]
[junit4:junit4] 2> 835237 T1723 C628 P20667 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty4/index.20130611130856335
[junit4:junit4] 2> 835238 T1723 C628 P20667 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty4/index.20130611130856335
[junit4:junit4] 2> 835238 T1723 C628 P20667 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 835238 T1723 C628 P20667 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 835238 T1723 C628 P20667 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 835239 T1723 C628 P20667 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 835276 T1723 C628 P20667 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 836193 T1627 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 836739 T1650 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 836740 T1650 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"5",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:20667_fjrpo%2Fi",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:20667/fjrpo/i"}
[junit4:junit4] 2> 836759 T1649 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> 836759 T1669 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> 836759 T1656 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> 836759 T1701 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> 836759 T1718 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> 836759 T1685 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> 837196 T1627 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 837198 T1627 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: collection1
[junit4:junit4] 2> ASYNC NEW_CORE C630 name=collection1 org.apache.solr.core.SolrCore@721cabbb url=http://127.0.0.1:62331/fjrpo/i/collection1 node=127.0.0.1:62331_fjrpo%2Fi C630_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:62331_fjrpo%2Fi, base_url=http://127.0.0.1:62331/fjrpo/i, leader=true}
[junit4:junit4] 2> 837207 T1639 C630 P62331 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 837211 T1639 C630 P62331 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2401ca0c lockFactory=org.apache.lucene.store.NativeFSLockFactory@430d56e3),segFN=segments_1,generation=1}
[junit4:junit4] 2> 837212 T1639 C630 P62331 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 837212 T1639 C630 P62331 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2401ca0c lockFactory=org.apache.lucene.store.NativeFSLockFactory@430d56e3),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2401ca0c lockFactory=org.apache.lucene.store.NativeFSLockFactory@430d56e3),segFN=segments_2,generation=2}
[junit4:junit4] 2> 837213 T1639 C630 P62331 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 837213 T1639 C630 P62331 oass.SolrIndexSearcher.<init> Opening Searcher@38aab85c main
[junit4:junit4] 2> 837214 T1639 C630 P62331 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 837215 T1653 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@38aab85c main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 837216 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 9
[junit4:junit4] 2> 837227 T1679 C629 P61466 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 837229 T1679 C629 P61466 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6ec3bd4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@603842a9),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@6ec3bd4 lockFactory=org.apache.lucene.store.NativeFSLockFactory@603842a9),segFN=segments_3,generation=3}
[junit4:junit4] 2> 837229 T1679 C629 P61466 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 837230 T1679 C629 P61466 oass.SolrIndexSearcher.<init> Opening Searcher@4a2237b5 main
[junit4:junit4] 2> 837230 T1679 C629 P61466 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 837231 T1687 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4a2237b5 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 837232 T1679 C629 P61466 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:20379/fjrpo/i/collection1/, StdNode: http://127.0.0.1:42284/fjrpo/i/collection1/, StdNode: http://127.0.0.1:20667/fjrpo/i/collection1/] params:commit_end_point=true&commit=true&softCommit=false&waitSearcher=true&expungeDeletes=false
[junit4:junit4] 2> 837234 T1663 C627 P20379 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 837236 T1663 C627 P20379 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@358fba1e lockFactory=org.apache.lucene.store.NativeFSLockFactory@6bcb92d4),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@358fba1e lockFactory=org.apache.lucene.store.NativeFSLockFactory@6bcb92d4),segFN=segments_3,generation=3}
[junit4:junit4] 2> 837236 T1663 C627 P20379 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 837237 T1663 C627 P20379 oass.SolrIndexSearcher.<init> Opening Searcher@296ff8fb main
[junit4:junit4] 2> 837237 T1663 C627 P20379 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 837238 T1671 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@296ff8fb main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 837239 T1663 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 5
[junit4:junit4] 2> C626_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:42284_fjrpo%2Fi, base_url=http://127.0.0.1:42284/fjrpo/i}
[junit4:junit4] 2> 837243 T1691 C626 P42284 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> C628_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:20667_fjrpo%2Fi, base_url=http://127.0.0.1:20667/fjrpo/i}
[junit4:junit4] 2> 837243 T1708 C628 P20667 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 837244 T1691 C626 P42284 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@398b50e9 lockFactory=org.apache.lucene.store.NativeFSLockFactory@437e3112),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@398b50e9 lockFactory=org.apache.lucene.store.NativeFSLockFactory@437e3112),segFN=segments_3,generation=3}
[junit4:junit4] 2> 837245 T1708 C628 P20667 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@39ff894b lockFactory=org.apache.lucene.store.NativeFSLockFactory@4a49a533),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@39ff894b lockFactory=org.apache.lucene.store.NativeFSLockFactory@4a49a533),segFN=segments_3,generation=3}
[junit4:junit4] 2> 837246 T1691 C626 P42284 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 837246 T1708 C628 P20667 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 837247 T1691 C626 P42284 oass.SolrIndexSearcher.<init> Opening Searcher@30687e1a main
[junit4:junit4] 2> 837247 T1708 C628 P20667 oass.SolrIndexSearcher.<init> Opening Searcher@6bf8ef98 main
[junit4:junit4] 2> 837248 T1691 C626 P42284 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 837248 T1708 C628 P20667 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 837249 T1703 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@30687e1a main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 837249 T1722 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6bf8ef98 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 837250 T1691 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 8
[junit4:junit4] 2> 837250 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 7
[junit4:junit4] 2> 837251 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 24
[junit4:junit4] 2> 837252 T1627 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 837255 T1664 C627 P20379 oasc.SolrCore.execute [collection1] webapp=/fjrpo/i path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4] 2> 837258 T1692 C626 P42284 oasc.SolrCore.execute [collection1] webapp=/fjrpo/i path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=1
[junit4:junit4] 2> 837259 T1680 C629 P61466 oasc.SolrCore.execute [collection1] webapp=/fjrpo/i path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4] 2> 837261 T1709 C628 P20667 oasc.SolrCore.execute [collection1] webapp=/fjrpo/i path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4] 2> 839267 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1437566805344256000)} 0 2
[junit4:junit4] 2> 839275 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={update.distrib=FROMLEADER&_version_=-1437566805348450304&update.from=http://127.0.0.1:20379/fjrpo/i/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1437566805348450304)} 0 1
[junit4:junit4] 2> 839278 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={update.distrib=FROMLEADER&_version_=-1437566805352644608&update.from=http://127.0.0.1:61466/fjrpo/i/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1437566805352644608)} 0 1
[junit4:junit4] 2> 839279 T1681 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={update.distrib=TOLEADER&wt=javabin&version=2} {deleteByQuery=*:* (-1437566805352644608)} 0 5
[junit4:junit4] 2> 839280 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1437566805348450304)} 0 11
[junit4:junit4] 2> 839284 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[0 (1437566805362081792)]} 0 1
[junit4:junit4] 2> 839291 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[0 (1437566805366276096)]} 0 1
[junit4:junit4] 2> 839291 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[0 (1437566805366276096)]} 0 4
[junit4:junit4] 2> 839294 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[1 (1437566805373616128)]} 0 0
[junit4:junit4] 2> 839300 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[1 (1437566805376761856)]} 0 0
[junit4:junit4] 2> 839301 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[1 (1437566805376761856)]} 0 4
[junit4:junit4] 2> 839304 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[2 (1437566805384101888)]} 0 0
[junit4:junit4] 2> 839311 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[2 (1437566805387247616)]} 0 1
[junit4:junit4] 2> 839311 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[2 (1437566805387247616)]} 0 4
[junit4:junit4] 2> 839314 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[3 (1437566805394587648)]} 0 0
[junit4:junit4] 2> 839322 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[3 (1437566805399830528)]} 0 0
[junit4:junit4] 2> 839323 T1681 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[3 (1437566805399830528)]} 0 4
[junit4:junit4] 2> 839324 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[3]} 0 7
[junit4:junit4] 2> 839326 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[4 (1437566805407170560)]} 0 0
[junit4:junit4] 2> 839332 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[4 (1437566805410316288)]} 0 0
[junit4:junit4] 2> 839333 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[4 (1437566805410316288)]} 0 4
[junit4:junit4] 2> 839336 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[5 (1437566805417656320)]} 0 0
[junit4:junit4] 2> 839342 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[5 (1437566805420802048)]} 0 0
[junit4:junit4] 2> 839343 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[5 (1437566805420802048)]} 0 4
[junit4:junit4] 2> 839346 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[6 (1437566805428142080)]} 0 0
[junit4:junit4] 2> 839354 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[6 (1437566805433384960)]} 0 0
[junit4:junit4] 2> 839355 T1681 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[6 (1437566805433384960)]} 0 4
[junit4:junit4] 2> 839356 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[6]} 0 7
[junit4:junit4] 2> 839358 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[7 (1437566805440724992)]} 0 0
[junit4:junit4] 2> 839364 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[7 (1437566805443870720)]} 0 0
[junit4:junit4] 2> 839365 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[7 (1437566805443870720)]} 0 4
[junit4:junit4] 2> 839368 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[8 (1437566805451210752)]} 0 0
[junit4:junit4] 2> 839374 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[8 (1437566805454356480)]} 0 0
[junit4:junit4] 2> 839375 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[8 (1437566805454356480)]} 0 4
[junit4:junit4] 2> 839378 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[9 (1437566805461696512)]} 0 0
[junit4:junit4] 2> 839384 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[9 (1437566805464842240)]} 0 0
[junit4:junit4] 2> 839385 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[9 (1437566805464842240)]} 0 4
[junit4:junit4] 2> 839388 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[10 (1437566805472182272)]} 0 0
[junit4:junit4] 2> 839395 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10 (1437566805475328000)]} 0 1
[junit4:junit4] 2> 839395 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[10 (1437566805475328000)]} 0 4
[junit4:junit4] 2> 839398 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[11 (1437566805482668032)]} 0 0
[junit4:junit4] 2> 839406 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[11 (1437566805487910912)]} 0 0
[junit4:junit4] 2> 839407 T1663 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[11 (1437566805487910912)]} 0 4
[junit4:junit4] 2> 839408 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[11]} 0 7
[junit4:junit4] 2> 839410 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[12 (1437566805495250944)]} 0 0
[junit4:junit4] 2> 839418 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[12 (1437566805500493824)]} 0 0
[junit4:junit4] 2> 839419 T1663 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[12 (1437566805500493824)]} 0 4
[junit4:junit4] 2> 839420 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[12]} 0 7
[junit4:junit4] 2> 839422 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[13 (1437566805507833856)]} 0 0
[junit4:junit4] 2> 839431 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[13 (1437566805513076736)]} 0 0
[junit4:junit4] 2> 839431 T1663 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[13 (1437566805513076736)]} 0 4
[junit4:junit4] 2> 839432 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[13]} 0 7
[junit4:junit4] 2> 839435 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[14 (1437566805521465344)]} 0 0
[junit4:junit4] 2> 839443 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[14 (1437566805526708224)]} 0 0
[junit4:junit4] 2> 839444 T1663 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[14 (1437566805526708224)]} 0 4
[junit4:junit4] 2> 839445 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[14]} 0 7
[junit4:junit4] 2> 839447 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[15 (1437566805534048256)]} 0 0
[junit4:junit4] 2> 839453 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[15 (1437566805537193984)]} 0 0
[junit4:junit4] 2> 839454 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[15 (1437566805537193984)]} 0 4
[junit4:junit4] 2> 839457 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[16 (1437566805544534016)]} 0 0
[junit4:junit4] 2> 839463 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[16 (1437566805547679744)]} 0 0
[junit4:junit4] 2> 839464 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[16 (1437566805547679744)]} 0 4
[junit4:junit4] 2> 839467 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[17 (1437566805555019776)]} 0 0
[junit4:junit4] 2> 839473 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[17 (1437566805558165504)]} 0 0
[junit4:junit4] 2> 839474 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[17 (1437566805558165504)]} 0 4
[junit4:junit4] 2> 839477 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[18 (1437566805565505536)]} 0 0
[junit4:junit4] 2> 839483 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[18 (1437566805568651264)]} 0 0
[junit4:junit4] 2> 839484 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[18 (1437566805568651264)]} 0 4
[junit4:junit4] 2> 839487 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[19 (1437566805575991296)]} 0 0
[junit4:junit4] 2> 839495 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[19 (1437566805581234176)]} 0 0
[junit4:junit4] 2> 839496 T1681 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[19 (1437566805581234176)]} 0 4
[junit4:junit4] 2> 839497 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[19]} 0 7
[junit4:junit4] 2> 839499 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[20 (1437566805588574208)]} 0 0
[junit4:junit4] 2> 839507 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[20 (1437566805593817088)]} 0 0
[junit4:junit4] 2> 839508 T1663 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[20 (1437566805593817088)]} 0 4
[junit4:junit4] 2> 839509 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[20]} 0 7
[junit4:junit4] 2> 839511 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[21 (1437566805601157120)]} 0 0
[junit4:junit4] 2> 839517 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[21 (1437566805604302848)]} 0 0
[junit4:junit4] 2> 839518 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[21 (1437566805604302848)]} 0 4
[junit4:junit4] 2> 839521 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[22 (1437566805611642880)]} 0 0
[junit4:junit4] 2> 839529 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[22 (1437566805616885760)]} 0 0
[junit4:junit4] 2> 839530 T1663 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[22 (1437566805616885760)]} 0 4
[junit4:junit4] 2> 839531 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[22]} 0 7
[junit4:junit4] 2> 839533 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[23 (1437566805624225792)]} 0 0
[junit4:junit4] 2> 839539 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[23 (1437566805627371520)]} 0 0
[junit4:junit4] 2> 839540 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[23 (1437566805627371520)]} 0 4
[junit4:junit4] 2> 839543 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[24 (1437566805634711552)]} 0 0
[junit4:junit4] 2> 839551 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[24 (1437566805639954432)]} 0 0
[junit4:junit4] 2> 839552 T1663 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[24 (1437566805639954432)]} 0 4
[junit4:junit4] 2> 839553 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[24]} 0 7
[junit4:junit4] 2> 839555 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[25 (1437566805647294464)]} 0 0
[junit4:junit4] 2> 839561 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[25 (1437566805650440192)]} 0 0
[junit4:junit4] 2> 839562 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[25 (1437566805650440192)]} 0 4
[junit4:junit4] 2> 839565 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[26 (1437566805657780224)]} 0 0
[junit4:junit4] 2> 839571 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[26 (1437566805660925952)]} 0 0
[junit4:junit4] 2> 839572 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[26 (1437566805660925952)]} 0 4
[junit4:junit4] 2> 839575 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[27 (1437566805668265984)]} 0 0
[junit4:junit4] 2> 839581 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[27 (1437566805671411712)]} 0 0
[junit4:junit4] 2> 839582 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[27 (1437566805671411712)]} 0 4
[junit4:junit4] 2> 839585 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[28 (1437566805678751744)]} 0 0
[junit4:junit4] 2> 839593 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[28 (1437566805683994624)]} 0 0
[junit4:junit4] 2> 839594 T1663 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[28 (1437566805683994624)]} 0 4
[junit4:junit4] 2> 839595 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[28]} 0 7
[junit4:junit4] 2> 839596 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[29 (1437566805690286080)]} 0 0
[junit4:junit4] 2> 839602 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[29 (1437566805693431808)]} 0 0
[junit4:junit4] 2> 839603 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[29 (1437566805693431808)]} 0 4
[junit4:junit4] 2> 839606 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[30 (1437566805700771840)]} 0 0
[junit4:junit4] 2> 839614 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[30 (1437566805706014720)]} 0 0
[junit4:junit4] 2> 839615 T1681 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[30 (1437566805706014720)]} 0 4
[junit4:junit4] 2> 839616 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[30]} 0 7
[junit4:junit4] 2> 839618 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[31 (1437566805713354752)]} 0 0
[junit4:junit4] 2> 839624 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[31 (1437566805716500480)]} 0 0
[junit4:junit4] 2> 839625 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[31 (1437566805716500480)]} 0 4
[junit4:junit4] 2> 839628 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[32 (1437566805723840512)]} 0 0
[junit4:junit4] 2> 839634 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[32 (1437566805726986240)]} 0 0
[junit4:junit4] 2> 839635 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[32 (1437566805726986240)]} 0 4
[junit4:junit4] 2> 839638 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[33 (1437566805734326272)]} 0 0
[junit4:junit4] 2> 839646 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[33 (1437566805739569152)]} 0 0
[junit4:junit4] 2> 839647 T1681 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[33 (1437566805739569152)]} 0 4
[junit4:junit4] 2> 839648 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[33]} 0 7
[junit4:junit4] 2> 839651 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[34 (1437566805747957760)]} 0 0
[junit4:junit4] 2> 839657 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[34 (1437566805751103488)]} 0 0
[junit4:junit4] 2> 839658 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[34 (1437566805751103488)]} 0 4
[junit4:junit4] 2> 839662 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[35 (1437566805758443520)]} 0 1
[junit4:junit4] 2> 839669 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[35 (1437566805763686400)]} 0 0
[junit4:junit4] 2> 839670 T1663 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[35 (1437566805763686400)]} 0 4
[junit4:junit4] 2> 839671 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[35]} 0 7
[junit4:junit4] 2> 839674 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[36 (1437566805772075008)]} 0 0
[junit4:junit4] 2> 839682 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[36 (1437566805777317888)]} 0 0
[junit4:junit4] 2> 839683 T1663 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[36 (1437566805777317888)]} 0 4
[junit4:junit4] 2> 839684 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[36]} 0 7
[junit4:junit4] 2> 839686 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[37 (1437566805784657920)]} 0 0
[junit4:junit4] 2> 839696 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[37 (1437566805790949376)]} 0 1
[junit4:junit4] 2> 839696 T1681 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[37 (1437566805790949376)]} 0 4
[junit4:junit4] 2> 839697 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[37]} 0 8
[junit4:junit4] 2> 839701 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[38 (1437566805799337984)]} 0 1
[junit4:junit4] 2> 839708 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[38 (1437566805804580864)]} 0 0
[junit4:junit4] 2> 839709 T1663 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[38 (1437566805804580864)]} 0 4
[junit4:junit4] 2> 839710 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[38]} 0 7
[junit4:junit4] 2> 839713 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[39 (1437566805812969472)]} 0 0
[junit4:junit4] 2> 839721 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[39 (1437566805818212352)]} 0 0
[junit4:junit4] 2> 839722 T1681 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[39 (1437566805818212352)]} 0 4
[junit4:junit4] 2> 839723 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[39]} 0 7
[junit4:junit4] 2> 839726 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[40 (1437566805825552384)]} 0 1
[junit4:junit4] 2> 839733 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[40 (1437566805829746688)]} 0 1
[junit4:junit4] 2> 839733 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[40 (1437566805829746688)]} 0 4
[junit4:junit4] 2> 839736 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[41 (1437566805837086720)]} 0 0
[junit4:junit4] 2> 839744 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[41 (1437566805842329600)]} 0 0
[junit4:junit4] 2> 839745 T1663 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[41 (1437566805842329600)]} 0 4
[junit4:junit4] 2> 839746 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[41]} 0 7
[junit4:junit4] 2> 839748 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[42 (1437566805849669632)]} 0 0
[junit4:junit4] 2> 839756 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[42 (1437566805854912512)]} 0 0
[junit4:junit4] 2> 839757 T1663 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[42 (1437566805854912512)]} 0 4
[junit4:junit4] 2> 839758 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[42]} 0 7
[junit4:junit4] 2> 839760 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[43 (1437566805862252544)]} 0 0
[junit4:junit4] 2> 839766 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[43 (1437566805865398272)]} 0 0
[junit4:junit4] 2> 839767 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[43 (1437566805865398272)]} 0 4
[junit4:junit4] 2> 839770 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[44 (1437566805872738304)]} 0 0
[junit4:junit4] 2> 839779 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[44 (1437566805877981184)]} 0 1
[junit4:junit4] 2> 839780 T1663 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[44 (1437566805877981184)]} 0 5
[junit4:junit4] 2> 839780 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[44]} 0 7
[junit4:junit4] 2> 839783 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[45 (1437566805886369792)]} 0 0
[junit4:junit4] 2> 839789 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[45 (1437566805889515520)]} 0 0
[junit4:junit4] 2> 839790 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[45 (1437566805889515520)]} 0 4
[junit4:junit4] 2> 839793 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[46 (1437566805896855552)]} 0 0
[junit4:junit4] 2> 839800 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[46 (1437566805900001280)]} 0 1
[junit4:junit4] 2> 839800 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[46 (1437566805900001280)]} 0 4
[junit4:junit4] 2> 839803 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[47 (1437566805907341312)]} 0 0
[junit4:junit4] 2> 839809 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[47 (1437566805910487040)]} 0 0
[junit4:junit4] 2> 839810 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[47 (1437566805910487040)]} 0 4
[junit4:junit4] 2> 839813 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[48 (1437566805917827072)]} 0 0
[junit4:junit4] 2> 839821 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[48 (1437566805923069952)]} 0 0
[junit4:junit4] 2> 839822 T1663 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[48 (1437566805923069952)]} 0 4
[junit4:junit4] 2> 839823 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[48]} 0 7
[junit4:junit4] 2> 839825 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[49 (1437566805930409984)]} 0 0
[junit4:junit4] 2> 839833 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[49 (1437566805935652864)]} 0 0
[junit4:junit4] 2> 839834 T1663 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[49 (1437566805935652864)]} 0 4
[junit4:junit4] 2> 839835 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[49]} 0 7
[junit4:junit4] 2> 839837 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[50 (1437566805942992896)]} 0 0
[junit4:junit4] 2> 839843 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[50 (1437566805946138624)]} 0 0
[junit4:junit4] 2> 839844 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[50 (1437566805946138624)]} 0 4
[junit4:junit4] 2> 839847 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[51 (1437566805953478656)]} 0 0
[junit4:junit4] 2> 839853 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[51 (1437566805956624384)]} 0 0
[junit4:junit4] 2> 839854 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[51 (1437566805956624384)]} 0 4
[junit4:junit4] 2> 839857 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[52 (1437566805963964416)]} 0 0
[junit4:junit4] 2> 839863 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[52 (1437566805967110144)]} 0 0
[junit4:junit4] 2> 839864 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[52 (1437566805967110144)]} 0 4
[junit4:junit4] 2> 839867 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[53 (1437566805974450176)]} 0 0
[junit4:junit4] 2> 839873 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[53 (1437566805977595904)]} 0 0
[junit4:junit4] 2> 839874 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[53 (1437566805977595904)]} 0 4
[junit4:junit4] 2> 839877 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[54 (1437566805984935936)]} 0 0
[junit4:junit4] 2> 839885 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[54 (1437566805990178816)]} 0 0
[junit4:junit4] 2> 839886 T1663 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[54 (1437566805990178816)]} 0 4
[junit4:junit4] 2> 839887 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[54]} 0 7
[junit4:junit4] 2> 839889 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[55 (1437566805997518848)]} 0 0
[junit4:junit4] 2> 839897 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[55 (1437566806002761728)]} 0 0
[junit4:junit4] 2> 839898 T1663 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[55 (1437566806002761728)]} 0 4
[junit4:junit4] 2> 839899 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[55]} 0 7
[junit4:junit4] 2> 839901 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[56 (1437566806010101760)]} 0 0
[junit4:junit4] 2> 839907 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[56 (1437566806013247488)]} 0 0
[junit4:junit4] 2> 839908 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[56 (1437566806013247488)]} 0 4
[junit4:junit4] 2> 839911 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[57 (1437566806020587520)]} 0 0
[junit4:junit4] 2> 839917 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[57 (1437566806023733248)]} 0 0
[junit4:junit4] 2> 839918 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[57 (1437566806023733248)]} 0 4
[junit4:junit4] 2> 839921 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[58 (1437566806031073280)]} 0 0
[junit4:junit4] 2> 839929 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[58 (1437566806036316160)]} 0 0
[junit4:junit4] 2> 839930 T1681 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[58 (1437566806036316160)]} 0 4
[junit4:junit4] 2> 839931 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[58]} 0 7
[junit4:junit4] 2> 839933 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[59 (1437566806043656192)]} 0 0
[junit4:junit4] 2> 839939 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[59 (1437566806046801920)]} 0 0
[junit4:junit4] 2> 839940 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[59 (1437566806046801920)]} 0 4
[junit4:junit4] 2> 839943 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[60 (1437566806054141952)]} 0 0
[junit4:junit4] 2> 839951 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[60 (1437566806059384832)]} 0 0
[junit4:junit4] 2> 839952 T1681 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[60 (1437566806059384832)]} 0 4
[junit4:junit4] 2> 839953 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[60]} 0 7
[junit4:junit4] 2> 839955 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[61 (1437566806066724864)]} 0 0
[junit4:junit4] 2> 839963 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[61 (1437566806071967744)]} 0 0
[junit4:junit4] 2> 839964 T1663 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[61 (1437566806071967744)]} 0 4
[junit4:junit4] 2> 839965 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[61]} 0 7
[junit4:junit4] 2> 839967 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[62 (1437566806079307776)]} 0 0
[junit4:junit4] 2> 839975 T1708 C628 P20667 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[62 (1437566806084550656)]} 0 0
[junit4:junit4] 2> 839976 T1681 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[62 (1437566806084550656)]} 0 4
[junit4:junit4] 2> 839977 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[62]} 0 7
[junit4:junit4] 2> 839979 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[63 (1437566806091890688)]} 0 0
[junit4:junit4] 2> 839987 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[63 (1437566806097133568)]} 0 0
[junit4:junit4] 2> 839988 T1663 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[63 (1437566806097133568)]} 0 4
[junit4:junit4] 2> 839989 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[63]} 0 7
[junit4:junit4] 2> 839991 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[64 (1437566806104473600)]} 0 0
[junit4:junit4] 2> 839997 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[64 (1437566806107619328)]} 0 0
[junit4:junit4] 2> 839998 T1665 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[64 (1437566806107619328)]} 0 4
[junit4:junit4] 2> 840001 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[65 (1437566806114959360)]} 0 0
[junit4:junit4] 2> 840009 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[65 (1437566806120202240)]} 0 0
[junit4:junit4] 2> 840010 T1663 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[65 (1437566806120202240)]} 0 4
[junit4:junit4] 2> 840011 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[65]} 0 7
[junit4:junit4] 2> 840013 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[66 (1437566806127542272)]} 0 0
[junit4:junit4] 2> 840021 T1693 C626 P42284 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:20379/fjrpo/i/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[66 (1437566806132785152)]} 0 0
[junit4:junit4] 2> 840022 T1663 C627 P20379 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={distrib.from=http://127.0.0.1:61466/fjrpo/i/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[66 (1437566806132785152)]} 0 4
[junit4:junit4] 2> 840023 T1679 C629 P61466 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[66]} 0 7
[junit4:junit4] 2> 840025 T1639 C630 P62331 oasup.LogUpdateProcessor.finish [collection1] webapp=/fjrpo/i path=/update params={wt=javabin&version=2} {add=[67 (1437566806140125184)]} 0 0
[junit4:junit4] 2> 840033 T1708 C628 P20667
[...truncated too long message...]
o/i"}
[junit4:junit4] 2> 1086009 T1627 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 20667
[junit4:junit4] 2> 1086009 T1627 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=745447670
[junit4:junit4] 2> 1086012 T1799 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=null message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"5",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "node_name":"127.0.0.1:20667_fjrpo%2Fi",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:20667/fjrpo/i"}
[junit4:junit4] 2> 1086024 T1718 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> 1087013 T1627 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1087014 T1627 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1087020 T1627 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@668a155d
[junit4:junit4] 2> 1087022 T1627 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=4,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=832,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4:junit4] 2> 1087023 T1627 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 1087023 T1627 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 1087024 T1627 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 1087026 T1627 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 1087027 T1627 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 1087027 T1627 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty4 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty4;done=false>>]
[junit4:junit4] 2> 1087028 T1627 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty4
[junit4:junit4] 2> 1087028 T1627 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty4/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty4/index;done=false>>]
[junit4:junit4] 2> 1087029 T1627 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429/jetty4/index
[junit4:junit4] 2> 1087030 T1799 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89847923503071244-127.0.0.1:20667_fjrpo%2Fi-n_0000000004) am no longer a leader.
[junit4:junit4] 2> 1087031 T1718 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 1087032 T1718 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> 1087032 T1627 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/fjrpo/i,null}
[junit4:junit4] 2> 1087032 T1718 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 1087103 T1627 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 1087105 T1627 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:34285 34285
[junit4:junit4] 2> 1087201 T1627 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 62331
[junit4:junit4] 2> !!!! WARNING: best effort to remove /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370970512429 FAILED !!!!!
[junit4:junit4] 2> 1087201 T1627 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 1087202 T1627 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:34285 34285
[junit4:junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4:junit4] 2> 1087256 T1701 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 1087298 T1701 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> 1087298 T1701 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeyShardSplitTest -Dtests.method=testDistribSearch -Dtests.seed=7F71725B76448567 -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_CO -Dtests.timezone=America/Guadeloupe -Dtests.file.encoding=US-ASCII
[junit4:junit4] ERROR 276s J1 | ChaosMonkeyShardSplitTest.testDistribSearch <<<
[junit4:junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:20379/fjrpo/i returned non ok status:500, message:Server Error
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([7F71725B76448567:FE97FC43011BE55B]:0)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
[junit4:junit4] > at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
[junit4:junit4] > at org.apache.solr.cloud.ShardSplitTest.splitShard(ShardSplitTest.java:228)
[junit4:junit4] > at org.apache.solr.cloud.ChaosMonkeyShardSplitTest.doTest(ChaosMonkeyShardSplitTest.java:136)
[junit4:junit4] > at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
[junit4:junit4] > at java.lang.Thread.run(Thread.java:722)
[junit4:junit4] 2> 1087299 T1627 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 275989 T1626 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 1 leaked thread(s).
[junit4:junit4] 2> NOTE: test params are: codec=Asserting, sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=es_CO, timezone=America/Guadeloupe
[junit4:junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_21 (64-bit)/cpus=16,threads=2,free=205676664,total=536870912
[junit4:junit4] 2> NOTE: All tests run in this JVM: [XmlUpdateRequestHandlerTest, TestCloudManagedSchema, TestFieldTypeResource, TestFunctionQuery, TestDefaultSimilarityFactory, TestSuggestSpellingConverter, TestAnalyzedSuggestions, ShardRoutingCustomTest, SuggesterTSTTest, SyncSliceTest, ShardSplitTest, FullSolrCloudDistribCmdsTest, OpenExchangeRatesOrgProviderTest, CoreAdminHandlerTest, TestManagedSchema, TestQuerySenderListener, TestXIncludeConfig, SolrCoreTest, TestElisionMultitermQuery, TestDynamicFieldCollectionResource, TestReloadAndDeleteDocs, TestSolrIndexConfig, QueryEqualityTest, TestCSVResponseWriter, TestRecovery, DistributedSpellCheckComponentTest, TestDocSet, LukeRequestHandlerTest, IndexBasedSpellCheckerTest, DirectUpdateHandlerTest, BadCopyFieldTest, FieldAnalysisRequestHandlerTest, RAMDirectoryFactoryTest, TestSolrQueryParserResource, TestPartialUpdateDeduplication, TestStressReorder, TestQueryUtils, TestCollationKeyRangeQueries, MinimalSchemaTest, ZkCLITest, TestFiltering, TestStressLucene, TestRangeQuery, TestSweetSpotSimilarityFactory, IndexSchemaTest, AlternateDirectoryTest, ZkControllerTest, ConvertedLegacyTest, TermVectorComponentDistributedTest, TestSort, TestPostingsSolrHighlighter, TestCoreContainer, SpellCheckCollatorTest, TestReload, SliceStateTest, TestArbitraryIndexDir, DocValuesTest, SolrCoreCheckLockOnStartupTest, CacheHeaderTest, TestBinaryField, FileBasedSpellCheckerTest, TestFieldResource, TestCoreDiscovery, TestLRUCache, TestRemoteStreaming, TestPHPSerializedResponseWriter, DefaultValueUpdateProcessorTest, ZkSolrClientTest, ZkNodePropsTest, WordBreakSolrSpellCheckerTest, LoggingHandlerTest, ChaosMonkeyShardSplitTest]
[junit4:junit4] Completed on J1 in 276.78s, 1 test, 1 error <<< FAILURES!
[...truncated 466 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:391: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:371: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build.xml:181: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/common-build.xml:437: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/lucene/common-build.xml:1243: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/lucene/common-build.xml:887: There were test failures: 297 suites, 1246 tests, 1 error, 13 ignored (7 assumptions)
Total time: 53 minutes 38 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure