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/02 00:00:34 UTC
[JENKINS] Lucene-Solr-Tests-4.x-Java7 - Build # 1300 - Still
Failing
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java7/1300/
1 tests failed.
REGRESSION: org.apache.solr.cloud.ChaosMonkeyShardSplitTest.testDistribSearch
Error Message:
Server at http://127.0.0.1:18672 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:18672 returned non ok status:500, message:Server Error
at __randomizedtesting.SeedInfo.seed([B14C329FC6F37C9D:30AABC87B1AC1CA1]: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:208)
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 9617 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.ChaosMonkeyShardSplitTest
[junit4:junit4] 2> 1022583 T2387 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4] 2> 1022589 T2387 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/J0/./solrtest-ChaosMonkeyShardSplitTest-1370123245694
[junit4:junit4] 2> 1022590 T2387 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 1022591 T2388 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 1022693 T2387 oasc.ZkTestServer.run start zk server on port:44437
[junit4:junit4] 2> 1022694 T2387 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1022735 T2394 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6aadd08e name:ZooKeeperConnection Watcher:127.0.0.1:44437 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1022736 T2387 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1022736 T2387 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 1022742 T2387 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1022754 T2396 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1673bfca name:ZooKeeperConnection Watcher:127.0.0.1:44437/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1022754 T2387 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1022754 T2387 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 1022764 T2387 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 1022767 T2387 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 1022770 T2387 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 1022779 T2387 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> 1022779 T2387 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 1022784 T2387 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> 1022785 T2387 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 1022893 T2387 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> 1022894 T2387 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 1022901 T2387 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> 1022902 T2387 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 1022905 T2387 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> 1022906 T2387 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 1022909 T2387 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> 1022909 T2387 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 1022912 T2387 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> 1022913 T2387 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 1022916 T2387 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> 1022917 T2387 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 1022920 T2387 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> 1022920 T2387 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 1023191 T2387 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1023196 T2387 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:59484
[junit4:junit4] 2> 1023196 T2387 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1023197 T2387 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1023197 T2387 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/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370123246033
[junit4:junit4] 2> 1023198 T2387 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/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370123246033/solr.xml
[junit4:junit4] 2> 1023198 T2387 oasc.CoreContainer.<init> New CoreContainer 302421146
[junit4:junit4] 2> 1023199 T2387 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/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370123246033/'
[junit4:junit4] 2> 1023200 T2387 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370123246033/'
[junit4:junit4] 2> 1023327 T2387 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1023327 T2387 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1023328 T2387 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1023328 T2387 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1023329 T2387 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1023329 T2387 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1023330 T2387 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1023330 T2387 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1023331 T2387 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1023331 T2387 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1023349 T2387 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1023350 T2387 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44437/solr
[junit4:junit4] 2> 1023350 T2387 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1023351 T2387 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1023354 T2407 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@20617f9 name:ZooKeeperConnection Watcher:127.0.0.1:44437 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1023354 T2387 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1023357 T2387 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1023370 T2387 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1023372 T2409 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1011630 name:ZooKeeperConnection Watcher:127.0.0.1:44437/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1023372 T2387 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1023374 T2387 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 1023384 T2387 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 1023387 T2387 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 1023389 T2387 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:59484_
[junit4:junit4] 2> 1023398 T2387 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:59484_
[junit4:junit4] 2> 1023401 T2387 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 1023415 T2387 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 1023422 T2387 oasc.Overseer.start Overseer (id=89792397030260739-127.0.0.1:59484_-n_0000000000) starting
[junit4:junit4] 2> 1023427 T2387 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 1023440 T2411 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 1023441 T2387 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 1023443 T2387 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 1023451 T2387 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1023453 T2410 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 1023458 T2412 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/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370123246033/collection1
[junit4:junit4] 2> 1023458 T2412 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 1023459 T2412 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1023459 T2412 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 1023461 T2412 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370123246033/collection1/'
[junit4:junit4] 2> 1023462 T2412 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370123246033/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1023463 T2412 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370123246033/collection1/lib/README' to classloader
[junit4:junit4] 2> 1023514 T2412 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 1023575 T2412 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1023677 T2412 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1023683 T2412 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 1024252 T2412 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1024256 T2412 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1024258 T2412 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1024263 T2412 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1024286 T2412 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1024286 T2412 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/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-controljetty-1370123246033/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/control/data/
[junit4:junit4] 2> 1024287 T2412 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@245a9783
[junit4:junit4] 2> 1024287 T2412 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1024288 T2412 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/control/data
[junit4:junit4] 2> 1024288 T2412 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/control/data/index/
[junit4:junit4] 2> 1024288 T2412 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1024291 T2412 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/control/data/index
[junit4:junit4] 2> 1024296 T2412 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/index3711537121tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@21b8faa1),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1024297 T2412 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1024299 T2412 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1024300 T2412 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1024301 T2412 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1024301 T2412 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1024302 T2412 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1024302 T2412 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1024302 T2412 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1024303 T2412 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1024303 T2412 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1024320 T2412 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1024329 T2412 oass.SolrIndexSearcher.<init> Opening Searcher@7feffda8 main
[junit4:junit4] 2> 1024329 T2412 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/control/data/tlog
[junit4:junit4] 2> 1024330 T2412 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1024330 T2412 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1024334 T2413 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7feffda8 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1024336 T2412 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1024337 T2412 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1024956 T2410 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1024957 T2410 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:59484_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:59484"}
[junit4:junit4] 2> 1024957 T2410 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 1024958 T2410 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 1024970 T2409 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> 1025339 T2412 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1025339 T2412 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:59484 collection:control_collection shard:shard1
[junit4:junit4] 2> 1025340 T2412 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 1025360 T2412 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 1025363 T2412 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 1025363 T2412 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 1025364 T2412 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:59484/collection1/
[junit4:junit4] 2> 1025364 T2412 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 1025364 T2412 oasc.SyncStrategy.syncToMe http://127.0.0.1:59484/collection1/ has no replicas
[junit4:junit4] 2> 1025364 T2412 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:59484/collection1/
[junit4:junit4] 2> 1025365 T2412 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 1026475 T2410 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1026508 T2409 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> 1026550 T2412 oasc.ZkController.register We are http://127.0.0.1:59484/collection1/ and leader is http://127.0.0.1:59484/collection1/
[junit4:junit4] 2> 1026550 T2412 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:59484
[junit4:junit4] 2> 1026550 T2412 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 1026550 T2412 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 1026551 T2412 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1026552 T2412 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1026554 T2387 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
[junit4:junit4] 2> 1026554 T2387 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1026554 T2387 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1026565 T2387 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 1026566 T2387 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1026568 T2416 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6728f481 name:ZooKeeperConnection Watcher:127.0.0.1:44437/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1026568 T2387 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1026570 T2387 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1026572 T2387 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 1026802 T2387 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1026805 T2387 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:18672
[junit4:junit4] 2> 1026806 T2387 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1026806 T2387 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1026807 T2387 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/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370123249677
[junit4:junit4] 2> 1026807 T2387 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/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370123249677/solr.xml
[junit4:junit4] 2> 1026808 T2387 oasc.CoreContainer.<init> New CoreContainer 1725419996
[junit4:junit4] 2> 1026809 T2387 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/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370123249677/'
[junit4:junit4] 2> 1026809 T2387 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370123249677/'
[junit4:junit4] 2> 1026936 T2387 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1026937 T2387 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1026938 T2387 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1026938 T2387 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1026939 T2387 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1026939 T2387 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1026940 T2387 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1026940 T2387 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1026941 T2387 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1026941 T2387 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1026957 T2387 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1026958 T2387 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44437/solr
[junit4:junit4] 2> 1026958 T2387 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1026959 T2387 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1026962 T2427 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@179ea91 name:ZooKeeperConnection Watcher:127.0.0.1:44437 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1026963 T2387 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1026973 T2387 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1026984 T2387 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1026992 T2429 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@52842fbd name:ZooKeeperConnection Watcher:127.0.0.1:44437/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1026992 T2387 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1027003 T2387 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1028006 T2387 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:18672_
[junit4:junit4] 2> 1028008 T2387 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:18672_
[junit4:junit4] 2> 1028011 T2409 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> 1028011 T2416 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 1028011 T2429 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 1028012 T2409 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 1028023 T2410 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1028024 T2410 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:59484__collection1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:59484_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:59484"}
[junit4:junit4] 2> 1028028 T2430 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/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370123249677/collection1
[junit4:junit4] 2> 1028028 T2409 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> 1028028 T2430 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 1028028 T2416 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> 1028028 T2429 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> 1028029 T2430 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1028029 T2430 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 1028039 T2430 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370123249677/collection1/'
[junit4:junit4] 2> 1028040 T2430 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370123249677/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1028041 T2430 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370123249677/collection1/lib/README' to classloader
[junit4:junit4] 2> 1028092 T2430 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 1028153 T2430 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1028255 T2430 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1028260 T2430 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 1028826 T2430 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1028830 T2430 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1028833 T2430 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1028838 T2430 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1028860 T2430 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1028861 T2430 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/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty1-1370123249677/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty1/
[junit4:junit4] 2> 1028861 T2430 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@245a9783
[junit4:junit4] 2> 1028862 T2430 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1028863 T2430 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty1
[junit4:junit4] 2> 1028863 T2430 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty1/index/
[junit4:junit4] 2> 1028863 T2430 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1028866 T2430 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty1/index
[junit4:junit4] 2> 1028870 T2430 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/index3711537122tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@49d04e0d),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1028871 T2430 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1028874 T2430 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1028874 T2430 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1028875 T2430 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1028876 T2430 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1028876 T2430 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1028877 T2430 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1028877 T2430 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1028878 T2430 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1028878 T2430 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1028895 T2430 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1028903 T2430 oass.SolrIndexSearcher.<init> Opening Searcher@480cd0f3 main
[junit4:junit4] 2> 1028904 T2430 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty1/tlog
[junit4:junit4] 2> 1028905 T2430 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1028905 T2430 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1028910 T2431 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@480cd0f3 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1028912 T2430 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1028912 T2430 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1029541 T2410 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1029542 T2410 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:18672_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:18672"}
[junit4:junit4] 2> 1029542 T2410 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 1029543 T2410 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 1029556 T2409 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> 1029556 T2429 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> 1029556 T2416 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> 1029916 T2430 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1029916 T2430 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:18672 collection:collection1 shard:shard1
[junit4:junit4] 2> 1029917 T2430 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 1029934 T2430 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 1029937 T2430 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 1029937 T2430 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 1029937 T2430 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:18672/collection1/
[junit4:junit4] 2> 1029937 T2430 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 1029938 T2430 oasc.SyncStrategy.syncToMe http://127.0.0.1:18672/collection1/ has no replicas
[junit4:junit4] 2> 1029938 T2430 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:18672/collection1/
[junit4:junit4] 2> 1029938 T2430 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 1031060 T2410 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1031086 T2409 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> 1031086 T2429 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> 1031086 T2416 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> 1031121 T2430 oasc.ZkController.register We are http://127.0.0.1:18672/collection1/ and leader is http://127.0.0.1:18672/collection1/
[junit4:junit4] 2> 1031121 T2430 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:18672
[junit4:junit4] 2> 1031121 T2430 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 1031121 T2430 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 1031122 T2430 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1031124 T2430 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1031126 T2387 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
[junit4:junit4] 2> 1031126 T2387 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1031127 T2387 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1031411 T2387 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1031414 T2387 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:25589
[junit4:junit4] 2> 1031415 T2387 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1031415 T2387 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1031416 T2387 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/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370123254247
[junit4:junit4] 2> 1031416 T2387 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/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370123254247/solr.xml
[junit4:junit4] 2> 1031417 T2387 oasc.CoreContainer.<init> New CoreContainer 1430589208
[junit4:junit4] 2> 1031418 T2387 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/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370123254247/'
[junit4:junit4] 2> 1031418 T2387 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370123254247/'
[junit4:junit4] 2> 1031545 T2387 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1031546 T2387 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1031547 T2387 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1031547 T2387 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1031548 T2387 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1031548 T2387 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1031549 T2387 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1031549 T2387 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1031550 T2387 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1031550 T2387 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1031566 T2387 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1031566 T2387 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44437/solr
[junit4:junit4] 2> 1031567 T2387 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1031568 T2387 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1031598 T2443 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b21e110 name:ZooKeeperConnection Watcher:127.0.0.1:44437 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1031599 T2387 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1031612 T2387 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1031622 T2387 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1031624 T2445 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@293e6de name:ZooKeeperConnection Watcher:127.0.0.1:44437/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1031625 T2387 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1031635 T2387 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1032591 T2410 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1032592 T2410 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:18672__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:18672_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:18672"}
[junit4:junit4] 2> 1032634 T2409 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> 1032634 T2445 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> 1032634 T2416 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> 1032634 T2429 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> 1032638 T2387 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:25589_
[junit4:junit4] 2> 1032640 T2387 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:25589_
[junit4:junit4] 2> 1032642 T2409 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> 1032642 T2445 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> 1032642 T2429 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> 1032642 T2416 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> 1032644 T2409 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 1032651 T2445 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 1032651 T2429 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 1032651 T2416 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 1032657 T2446 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/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370123254247/collection1
[junit4:junit4] 2> 1032657 T2446 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 1032657 T2446 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1032658 T2446 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 1032659 T2446 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370123254247/collection1/'
[junit4:junit4] 2> 1032661 T2446 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370123254247/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1032661 T2446 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370123254247/collection1/lib/README' to classloader
[junit4:junit4] 2> 1032713 T2446 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 1032773 T2446 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1032875 T2446 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1032881 T2446 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 1033445 T2446 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1033449 T2446 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1033452 T2446 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1033457 T2446 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1033480 T2446 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1033480 T2446 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/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty2-1370123254247/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty2/
[junit4:junit4] 2> 1033480 T2446 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@245a9783
[junit4:junit4] 2> 1033481 T2446 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1033482 T2446 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty2
[junit4:junit4] 2> 1033482 T2446 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty2/index/
[junit4:junit4] 2> 1033483 T2446 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1033485 T2446 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty2/index
[junit4:junit4] 2> 1033490 T2446 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/index3711537123tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@172e3919),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1033490 T2446 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1033493 T2446 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1033493 T2446 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1033494 T2446 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1033495 T2446 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1033495 T2446 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1033496 T2446 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1033496 T2446 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1033497 T2446 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1033497 T2446 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1033513 T2446 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1033522 T2446 oass.SolrIndexSearcher.<init> Opening Searcher@2c6290dc main
[junit4:junit4] 2> 1033522 T2446 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty2/tlog
[junit4:junit4] 2> 1033523 T2446 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1033524 T2446 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1033529 T2447 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2c6290dc main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1033531 T2446 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1033531 T2446 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1034139 T2410 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1034140 T2410 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:25589_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:25589"}
[junit4:junit4] 2> 1034140 T2410 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 1034141 T2410 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 1034158 T2409 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> 1034158 T2445 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> 1034158 T2416 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> 1034158 T2429 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> 1034534 T2446 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1034534 T2446 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:25589 collection:collection1 shard:shard2
[junit4:junit4] 2> 1034535 T2446 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 1034551 T2446 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 1034560 T2446 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 1034561 T2446 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 1034561 T2446 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:25589/collection1/
[junit4:junit4] 2> 1034561 T2446 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 1034561 T2446 oasc.SyncStrategy.syncToMe http://127.0.0.1:25589/collection1/ has no replicas
[junit4:junit4] 2> 1034562 T2446 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:25589/collection1/
[junit4:junit4] 2> 1034562 T2446 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 1035663 T2410 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1035685 T2409 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> 1035685 T2429 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> 1035685 T2445 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> 1035685 T2416 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> 1035704 T2446 oasc.ZkController.register We are http://127.0.0.1:25589/collection1/ and leader is http://127.0.0.1:25589/collection1/
[junit4:junit4] 2> 1035704 T2446 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:25589
[junit4:junit4] 2> 1035704 T2446 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 1035704 T2446 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 1035705 T2446 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1035707 T2446 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1035708 T2387 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
[junit4:junit4] 2> 1035708 T2387 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1035709 T2387 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1035991 T2387 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1035994 T2387 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:15430
[junit4:junit4] 2> 1035995 T2387 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1035996 T2387 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1035996 T2387 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/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370123258831
[junit4:junit4] 2> 1035997 T2387 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/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370123258831/solr.xml
[junit4:junit4] 2> 1035997 T2387 oasc.CoreContainer.<init> New CoreContainer 731866148
[junit4:junit4] 2> 1035998 T2387 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/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370123258831/'
[junit4:junit4] 2> 1035999 T2387 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370123258831/'
[junit4:junit4] 2> 1036125 T2387 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1036126 T2387 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1036127 T2387 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1036127 T2387 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1036128 T2387 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1036128 T2387 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1036129 T2387 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1036129 T2387 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1036130 T2387 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1036130 T2387 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1036147 T2387 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1036148 T2387 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44437/solr
[junit4:junit4] 2> 1036149 T2387 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1036150 T2387 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1036156 T2459 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2d730d11 name:ZooKeeperConnection Watcher:127.0.0.1:44437 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1036157 T2387 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1036178 T2387 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1036190 T2387 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1036193 T2461 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@547d5390 name:ZooKeeperConnection Watcher:127.0.0.1:44437/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1036193 T2387 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1036203 T2387 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1037190 T2410 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1037191 T2410 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:25589__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:25589_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:25589"}
[junit4:junit4] 2> 1037196 T2409 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> 1037196 T2429 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> 1037196 T2445 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> 1037196 T2461 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> 1037196 T2416 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> 1037211 T2387 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:15430_
[junit4:junit4] 2> 1037213 T2387 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:15430_
[junit4:junit4] 2> 1037215 T2409 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> 1037215 T2445 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> 1037215 T2429 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> 1037215 T2461 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> 1037215 T2416 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> 1037217 T2409 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1037217 T2445 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1037223 T2429 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1037224 T2416 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1037224 T2461 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1037229 T2462 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/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370123258831/collection1
[junit4:junit4] 2> 1037229 T2462 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 1037230 T2462 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1037230 T2462 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 1037232 T2462 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370123258831/collection1/'
[junit4:junit4] 2> 1037233 T2462 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370123258831/collection1/lib/README' to classloader
[junit4:junit4] 2> 1037234 T2462 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370123258831/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1037285 T2462 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 1037360 T2462 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1037462 T2462 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1037467 T2462 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 1038017 T2462 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1038022 T2462 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1038024 T2462 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1038029 T2462 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1038051 T2462 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1038052 T2462 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/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty3-1370123258831/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty3/
[junit4:junit4] 2> 1038052 T2462 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@245a9783
[junit4:junit4] 2> 1038053 T2462 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1038053 T2462 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty3
[junit4:junit4] 2> 1038054 T2462 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty3/index/
[junit4:junit4] 2> 1038054 T2462 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1038056 T2462 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty3/index
[junit4:junit4] 2> 1038061 T2462 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/index3711537124tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@564662e7),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1038062 T2462 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1038065 T2462 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1038065 T2462 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1038066 T2462 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1038067 T2462 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1038067 T2462 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1038067 T2462 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1038068 T2462 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1038069 T2462 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1038069 T2462 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1038085 T2462 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1038094 T2462 oass.SolrIndexSearcher.<init> Opening Searcher@627338d2 main
[junit4:junit4] 2> 1038094 T2462 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty3/tlog
[junit4:junit4] 2> 1038095 T2462 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1038096 T2462 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1038100 T2463 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@627338d2 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1038103 T2462 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1038103 T2462 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1038714 T2410 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1038715 T2410 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:15430_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:15430"}
[junit4:junit4] 2> 1038715 T2410 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 1038716 T2410 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 1038731 T2409 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> 1038731 T2445 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> 1038731 T2416 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> 1038731 T2429 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> 1038731 T2461 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> 1039106 T2462 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1039106 T2462 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:15430 collection:collection1 shard:shard1
[junit4:junit4] 2> 1039109 T2462 oasc.ZkController.register We are http://127.0.0.1:15430/collection1/ and leader is http://127.0.0.1:18672/collection1/
[junit4:junit4] 2> 1039109 T2462 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:15430
[junit4:junit4] 2> 1039110 T2462 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 1039110 T2462 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C666 name=collection1 org.apache.solr.core.SolrCore@4719dad8 url=http://127.0.0.1:15430/collection1 node=127.0.0.1:15430_ C666_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:15430_, base_url=http://127.0.0.1:15430}
[junit4:junit4] 2> 1039110 T2464 C666 P15430 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 1039111 T2462 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1039111 T2464 C666 P15430 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 1039112 T2464 C666 P15430 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 1039112 T2464 C666 P15430 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1039112 T2387 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
[junit4:junit4] 2> 1039113 T2387 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1039113 T2464 C666 P15430 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1039114 T2387 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1039138 T2419 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:15430__collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 1039410 T2387 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1039413 T2387 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:51860
[junit4:junit4] 2> 1039414 T2387 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1039415 T2387 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1039415 T2387 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/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370123262240
[junit4:junit4] 2> 1039416 T2387 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/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370123262240/solr.xml
[junit4:junit4] 2> 1039416 T2387 oasc.CoreContainer.<init> New CoreContainer 1753521914
[junit4:junit4] 2> 1039417 T2387 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/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370123262240/'
[junit4:junit4] 2> 1039418 T2387 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370123262240/'
[junit4:junit4] 2> 1039546 T2387 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1039547 T2387 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1039548 T2387 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1039548 T2387 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1039549 T2387 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1039549 T2387 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1039550 T2387 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1039550 T2387 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1039551 T2387 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1039551 T2387 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1039567 T2387 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1039568 T2387 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:44437/solr
[junit4:junit4] 2> 1039569 T2387 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1039570 T2387 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1039573 T2476 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@b982f11 name:ZooKeeperConnection Watcher:127.0.0.1:44437 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1039573 T2387 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1039588 T2387 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1039599 T2387 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1039601 T2478 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@c2fb5cd name:ZooKeeperConnection Watcher:127.0.0.1:44437/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1039601 T2387 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1039610 T2387 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1040236 T2410 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1040237 T2410 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:15430__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:15430_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:15430"}
[junit4:junit4] 2> 1040251 T2409 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> 1040251 T2461 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> 1040251 T2429 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> 1040251 T2445 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> 1040251 T2478 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> 1040251 T2416 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> 1040614 T2387 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:51860_
[junit4:junit4] 2> 1040616 T2387 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:51860_
[junit4:junit4] 2> 1040618 T2478 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> 1040618 T2445 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> 1040618 T2429 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> 1040618 T2461 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> 1040618 T2416 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> 1040618 T2409 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> 1040620 T2478 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1040628 T2445 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1040629 T2429 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1040629 T2461 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1040629 T2416 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1040629 T2409 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1040634 T2479 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/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370123262240/collection1
[junit4:junit4] 2> 1040635 T2479 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 1040635 T2479 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1040636 T2479 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 1040637 T2479 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370123262240/collection1/'
[junit4:junit4] 2> 1040639 T2479 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370123262240/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1040639 T2479 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370123262240/collection1/lib/README' to classloader
[junit4:junit4] 2> 1040706 T2479 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 1040769 T2479 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1040872 T2479 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1040878 T2479 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 1041140 T2419 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:15430__collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 2 seconds.
[junit4:junit4] 2> 1041140 T2419 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:15430__collection1&state=recovering&nodeName=127.0.0.1:15430_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=2002
[junit4:junit4] 2> 1041428 T2479 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1041432 T2479 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1041434 T2479 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1041439 T2479 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1041462 T2479 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1041462 T2479 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/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-jetty4-1370123262240/collection1/, dataDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty4/
[junit4:junit4] 2> 1041463 T2479 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@245a9783
[junit4:junit4] 2> 1041463 T2479 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1041464 T2479 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty4
[junit4:junit4] 2> 1041464 T2479 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty4/index/
[junit4:junit4] 2> 1041465 T2479 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1041467 T2479 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty4/index
[junit4:junit4] 2> 1041472 T2479 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/index3711537125tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@24896675),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1041472 T2479 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1041475 T2479 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1041476 T2479 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1041476 T2479 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1041477 T2479 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1041478 T2479 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1041478 T2479 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1041479 T2479 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1041479 T2479 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1041480 T2479 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1041496 T2479 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1041504 T2479 oass.SolrIndexSearcher.<init> Opening Searcher@652a0ce9 main
[junit4:junit4] 2> 1041505 T2479 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty4/tlog
[junit4:junit4] 2> 1041506 T2479 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1041506 T2479 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1041511 T2480 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@652a0ce9 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1041514 T2479 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1041514 T2479 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1041757 T2410 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1041758 T2410 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":null,
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:51860_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:51860"}
[junit4:junit4] 2> 1041758 T2410 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 1041758 T2410 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 1041774 T2416 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> 1041774 T2445 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> 1041774 T2429 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> 1041774 T2409 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> 1041774 T2461 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> 1041774 T2478 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> 1042520 T2479 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1042520 T2479 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:51860 collection:collection1 shard:shard2
[junit4:junit4] 2> 1042532 T2479 oasc.ZkController.register We are http://127.0.0.1:51860/collection1/ and leader is http://127.0.0.1:25589/collection1/
[junit4:junit4] 2> 1042532 T2479 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:51860
[junit4:junit4] 2> 1042533 T2479 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 1042533 T2479 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C667 name=collection1 org.apache.solr.core.SolrCore@3a661f1f url=http://127.0.0.1:51860/collection1 node=127.0.0.1:51860_ C667_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:51860_, base_url=http://127.0.0.1:51860}
[junit4:junit4] 2> 1042533 T2481 C667 P51860 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 1042534 T2479 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1042534 T2481 C667 P51860 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 1042534 T2481 C667 P51860 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 1042535 T2481 C667 P51860 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1042535 T2387 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0
[junit4:junit4] 2> 1042536 T2387 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1042536 T2481 C667 P51860 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1042536 T2387 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1042554 T2387 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1042555 T2435 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 127.0.0.1:51860__collection1, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 1042556 T2387 oasc.AbstractFullDistribZkTestBase.waitForThingsToLevelOut Wait for recoveries to finish - wait 15 for each attempt
[junit4:junit4] 2> 1042556 T2387 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):15
[junit4:junit4] 2> 1042557 T2387 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> ASYNC NEW_CORE C668 name=collection1 org.apache.solr.core.SolrCore@4719dad8 url=http://127.0.0.1:15430/collection1 node=127.0.0.1:15430_ C668_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:15430_, base_url=http://127.0.0.1:15430}
[junit4:junit4] 2> 1043142 T2464 C668 P15430 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:18672/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 1043142 T2464 C668 P15430 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:15430 START replicas=[http://127.0.0.1:18672/collection1/] nUpdates=100
[junit4:junit4] 2> 1043143 T2464 C668 P15430 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 1043143 T2464 C668 P15430 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 1043144 T2464 C668 P15430 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 1043144 T2464 C668 P15430 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 1043144 T2464 C668 P15430 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 1043144 T2464 C668 P15430 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:18672/collection1/. core=collection1
[junit4:junit4] 2> 1043145 T2464 C668 P15430 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C669 name=collection1 org.apache.solr.core.SolrCore@6d884d08 url=http://127.0.0.1:18672/collection1 node=127.0.0.1:18672_ C669_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:18672_, base_url=http://127.0.0.1:18672, leader=true}
[junit4:junit4] 2> 1043151 T2420 C669 P18672 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 1043156 T2421 C669 P18672 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1043161 T2421 C669 P18672 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/index3711537122tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@49d04e0d),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1043161 T2421 C669 P18672 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1043163 T2421 C669 P18672 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/index3711537122tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@49d04e0d),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/index3711537122tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@49d04e0d),segFN=segments_2,generation=2}
[junit4:junit4] 2> 1043164 T2421 C669 P18672 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1043165 T2421 C669 P18672 oass.SolrIndexSearcher.<init> Opening Searcher@3758cbb9 realtime
[junit4:junit4] 2> 1043165 T2421 C669 P18672 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1043166 T2421 C669 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 10
[junit4:junit4] 2> 1043167 T2464 C668 P15430 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 1043167 T2464 C668 P15430 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 1043169 T2422 C669 P18672 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 1043169 T2422 C669 P18672 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> 1043170 T2464 C668 P15430 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 1043170 T2464 C668 P15430 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 1043170 T2464 C668 P15430 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 1043173 T2422 C669 P18672 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=0
[junit4:junit4] 2> 1043174 T2464 C668 P15430 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 1043175 T2464 C668 P15430 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty3/index.20130601174746279
[junit4:junit4] 2> 1043176 T2464 C668 P15430 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@694f15db lockFactory=org.apache.lucene.store.NativeFSLockFactory@75d8184d) fullCopy=false
[junit4:junit4] 2> 1043179 T2422 C669 P18672 oasc.SolrCore.execute [collection1] webapp= path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 1043181 T2464 C668 P15430 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 1043182 T2464 C668 P15430 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 1043182 T2464 C668 P15430 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 1043186 T2464 C668 P15430 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/index3711537124tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@564662e7),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/index3711537124tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@564662e7),segFN=segments_2,generation=2}
[junit4:junit4] 2> 1043186 T2464 C668 P15430 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1043187 T2464 C668 P15430 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 1043187 T2464 C668 P15430 oass.SolrIndexSearcher.<init> Opening Searcher@5e1e4c80 main
[junit4:junit4] 2> 1043189 T2463 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5e1e4c80 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1043189 T2464 C668 P15430 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty3/index.20130601174746279 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty3/index.20130601174746279;done=true>>]
[junit4:junit4] 2> 1043189 T2464 C668 P15430 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty3/index.20130601174746279
[junit4:junit4] 2> 1043190 T2464 C668 P15430 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty3/index.20130601174746279
[junit4:junit4] 2> 1043190 T2464 C668 P15430 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 1043190 T2464 C668 P15430 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 1043190 T2464 C668 P15430 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 1043191 T2464 C668 P15430 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1043192 T2464 C668 P15430 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 1043279 T2410 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1043280 T2410 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:51860__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:51860_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:51860"}
[junit4:junit4] 2> 1043283 T2410 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:15430__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:15430_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:15430"}
[junit4:junit4] 2> 1043295 T2409 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> 1043296 T2445 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> 1043295 T2429 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> 1043295 T2478 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> 1043295 T2416 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> 1043295 T2461 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> 1043557 T2435 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 127.0.0.1:51860__collection1, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 1043557 T2435 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=127.0.0.1:51860__collection1&state=recovering&nodeName=127.0.0.1:51860_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1002
[junit4:junit4] 2> 1043559 T2387 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1044561 T2387 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> C667_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:51860_, base_url=http://127.0.0.1:51860}
[junit4:junit4] 2> 1045560 T2481 C667 P51860 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:25589/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 1045560 T2481 C667 P51860 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:51860 START replicas=[http://127.0.0.1:25589/collection1/] nUpdates=100
[junit4:junit4] 2> 1045561 T2481 C667 P51860 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 1045561 T2481 C667 P51860 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 1045561 T2481 C667 P51860 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 1045561 T2481 C667 P51860 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 1045562 T2481 C667 P51860 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 1045562 T2481 C667 P51860 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:25589/collection1/. core=collection1
[junit4:junit4] 2> 1045562 T2481 C667 P51860 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1045563 T2387 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> ASYNC NEW_CORE C670 name=collection1 org.apache.solr.core.SolrCore@2f7d3a1e url=http://127.0.0.1:25589/collection1 node=127.0.0.1:25589_ C670_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:25589_, base_url=http://127.0.0.1:25589, leader=true}
[junit4:junit4] 2> 1045574 T2436 C670 P25589 oasc.SolrCore.execute [collection1] webapp= path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 1045579 T2437 C670 P25589 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1045584 T2437 C670 P25589 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/index3711537123tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@172e3919),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1045584 T2437 C670 P25589 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1045587 T2437 C670 P25589 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/index3711537123tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@172e3919),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/index3711537123tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@172e3919),segFN=segments_2,generation=2}
[junit4:junit4] 2> 1045587 T2437 C670 P25589 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1045588 T2437 C670 P25589 oass.SolrIndexSearcher.<init> Opening Searcher@47d90d9a realtime
[junit4:junit4] 2> 1045589 T2437 C670 P25589 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1045589 T2437 C670 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 10
[junit4:junit4] 2> 1045590 T2481 C667 P51860 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 1045590 T2481 C667 P51860 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 1045592 T2438 C670 P25589 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 1045592 T2438 C670 P25589 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> 1045593 T2481 C667 P51860 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 1045593 T2481 C667 P51860 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 1045593 T2481 C667 P51860 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 1045596 T2438 C670 P25589 oasc.SolrCore.execute [collection1] webapp= path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=0
[junit4:junit4] 2> 1045597 T2481 C667 P51860 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 1045598 T2481 C667 P51860 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty4/index.20130601174748701
[junit4:junit4] 2> 1045599 T2481 C667 P51860 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@307f1844 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7d4a2b08) fullCopy=false
[junit4:junit4] 2> 1045601 T2438 C670 P25589 oasc.SolrCore.execute [collection1] webapp= path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 1045602 T2481 C667 P51860 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 1045604 T2481 C667 P51860 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 1045604 T2481 C667 P51860 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 1045608 T2481 C667 P51860 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/index3711537125tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@24896675),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/index3711537125tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@24896675),segFN=segments_2,generation=2}
[junit4:junit4] 2> 1045608 T2481 C667 P51860 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1045609 T2481 C667 P51860 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 1045609 T2481 C667 P51860 oass.SolrIndexSearcher.<init> Opening Searcher@59feb436 main
[junit4:junit4] 2> 1045610 T2480 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@59feb436 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1045611 T2481 C667 P51860 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty4/index.20130601174748701 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty4/index.20130601174748701;done=true>>]
[junit4:junit4] 2> 1045611 T2481 C667 P51860 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty4/index.20130601174748701
[junit4:junit4] 2> 1045612 T2481 C667 P51860 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty4/index.20130601174748701
[junit4:junit4] 2> 1045612 T2481 C667 P51860 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 1045612 T2481 C667 P51860 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 1045612 T2481 C667 P51860 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 1045612 T2481 C667 P51860 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1045614 T2481 C667 P51860 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 1046312 T2410 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1046313 T2410 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"127.0.0.1:51860__collection1",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:51860_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:51860"}
[junit4:junit4] 2> 1046354 T2409 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> 1046354 T2461 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> 1046354 T2429 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> 1046354 T2445 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> 1046354 T2478 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> 1046354 T2416 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> 1046566 T2387 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1046567 T2387 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: collection1
[junit4:junit4] 2> ASYNC NEW_CORE C671 name=collection1 org.apache.solr.core.SolrCore@3820bf81 url=http://127.0.0.1:59484/collection1 node=127.0.0.1:59484_ C671_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:59484_, base_url=http://127.0.0.1:59484, leader=true}
[junit4:junit4] 2> 1046580 T2399 C671 P59484 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1046585 T2399 C671 P59484 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/index3711537121tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@21b8faa1),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1046585 T2399 C671 P59484 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1046588 T2399 C671 P59484 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/index3711537121tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@21b8faa1),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/index3711537121tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@21b8faa1),segFN=segments_2,generation=2}
[junit4:junit4] 2> 1046588 T2399 C671 P59484 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1046589 T2399 C671 P59484 oass.SolrIndexSearcher.<init> Opening Searcher@78b52c03 main
[junit4:junit4] 2> 1046590 T2399 C671 P59484 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1046591 T2413 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@78b52c03 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1046591 T2399 C671 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 11
[junit4:junit4] 2> 1046603 T2423 C669 P18672 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1046606 T2423 C669 P18672 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/index3711537122tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@49d04e0d),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/index3711537122tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@49d04e0d),segFN=segments_3,generation=3}
[junit4:junit4] 2> 1046607 T2423 C669 P18672 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 1046607 T2423 C669 P18672 oass.SolrIndexSearcher.<init> Opening Searcher@54ee7d19 main
[junit4:junit4] 2> 1046608 T2423 C669 P18672 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1046609 T2431 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@54ee7d19 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1046609 T2423 C669 P18672 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:15430/collection1/, StdNode: http://127.0.0.1:25589/collection1/, StdNode: http://127.0.0.1:51860/collection1/] params:commit_end_point=true&commit=true&softCommit=false&waitSearcher=true&expungeDeletes=false
[junit4:junit4] 2> 1046612 T2439 C670 P25589 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1046617 T2439 C670 P25589 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/index3711537123tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@172e3919),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/index3711537123tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@172e3919),segFN=segments_3,generation=3}
[junit4:junit4] 2> 1046618 T2439 C670 P25589 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 1046618 T2439 C670 P25589 oass.SolrIndexSearcher.<init> Opening Searcher@6a289630 main
[junit4:junit4] 2> 1046619 T2439 C670 P25589 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1046620 T2447 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6a289630 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1046620 T2439 C670 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 8
[junit4:junit4] 2> ASYNC NEW_CORE C672 name=collection1 org.apache.solr.core.SolrCore@4719dad8 url=http://127.0.0.1:15430/collection1 node=127.0.0.1:15430_ C672_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:15430_, base_url=http://127.0.0.1:15430}
[junit4:junit4] 2> 1046647 T2451 C672 P15430 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> ASYNC NEW_CORE C673 name=collection1 org.apache.solr.core.SolrCore@3a661f1f url=http://127.0.0.1:51860/collection1 node=127.0.0.1:51860_ C673_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:51860_, base_url=http://127.0.0.1:51860}
[junit4:junit4] 2> 1046647 T2468 C673 P51860 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1046651 T2451 C672 P15430 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/index3711537124tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@564662e7),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/index3711537124tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@564662e7),segFN=segments_3,generation=3}
[junit4:junit4] 2> 1046651 T2451 C672 P15430 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 1046652 T2468 C673 P51860 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/index3711537125tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@24896675),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.SimpleFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/solr/build/solr-core/test/J0/index3711537125tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@24896675),segFN=segments_3,generation=3}
[junit4:junit4] 2> 1046653 T2468 C673 P51860 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 1046653 T2451 C672 P15430 oass.SolrIndexSearcher.<init> Opening Searcher@32711960 main
[junit4:junit4] 2> 1046654 T2451 C672 P15430 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1046654 T2468 C673 P51860 oass.SolrIndexSearcher.<init> Opening Searcher@6cd22fd7 main
[junit4:junit4] 2> 1046655 T2463 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@32711960 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1046655 T2468 C673 P51860 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1046655 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 8
[junit4:junit4] 2> 1046655 T2480 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6cd22fd7 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1046656 T2468 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 9
[junit4:junit4] 2> ASYNC NEW_CORE C674 name=collection1 org.apache.solr.core.SolrCore@6d884d08 url=http://127.0.0.1:18672/collection1 node=127.0.0.1:18672_ C674_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:18672_, base_url=http://127.0.0.1:18672, leader=true}
[junit4:junit4] 2> 1046657 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 54
[junit4:junit4] 2> 1046658 T2387 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1046661 T2424 C674 P18672 oasc.SolrCore.execute [collection1] webapp= path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4] 2> 1046663 T2452 C672 P15430 oasc.SolrCore.execute [collection1] webapp= path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4] 2> ASYNC NEW_CORE C675 name=collection1 org.apache.solr.core.SolrCore@2f7d3a1e url=http://127.0.0.1:25589/collection1 node=127.0.0.1:25589_ C675_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:25589_, base_url=http://127.0.0.1:25589, leader=true}
[junit4:junit4] 2> 1046665 T2440 C675 P25589 oasc.SolrCore.execute [collection1] webapp= path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4] 2> 1046667 T2469 C673 P51860 oasc.SolrCore.execute [collection1] webapp= path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4] 2> ASYNC NEW_CORE C676 name=collection1 org.apache.solr.core.SolrCore@3820bf81 url=http://127.0.0.1:59484/collection1 node=127.0.0.1:59484_ C676_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:59484_, base_url=http://127.0.0.1:59484, leader=true}
[junit4:junit4] 2> 1048673 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1436678379825790976)} 0 2
[junit4:junit4] 2> 1048681 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={update.distrib=FROMLEADER&_version_=-1436678379828936704&update.from=http://127.0.0.1:25589/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1436678379828936704)} 0 1
[junit4:junit4] 2> 1048685 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={update.distrib=FROMLEADER&_version_=-1436678379834179584&update.from=http://127.0.0.1:18672/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1436678379834179584)} 0 1
[junit4:junit4] 2> 1048686 T2425 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={update.distrib=TOLEADER&wt=javabin&version=2} {deleteByQuery=*:* (-1436678379834179584)} 0 6
[junit4:junit4] 2> 1048687 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1436678379828936704)} 0 12
[junit4:junit4] 2> 1048692 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[0 (1436678379844665344)]} 0 2
[junit4:junit4] 2> 1048701 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[0 (1436678379849908224)]} 0 2
[junit4:junit4] 2> 1048702 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[0 (1436678379849908224)]} 0 7
[junit4:junit4] 2> 1048707 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[1 (1436678379861442560)]} 0 1
[junit4:junit4] 2> 1048712 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[1 (1436678379864588288)]} 0 0
[junit4:junit4] 2> 1048713 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[1 (1436678379864588288)]} 0 4
[junit4:junit4] 2> 1048717 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[2 (1436678379872976896)]} 0 0
[junit4:junit4] 2> 1048727 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[2 (1436678379877171200)]} 0 2
[junit4:junit4] 2> 1048728 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[2 (1436678379877171200)]} 0 7
[junit4:junit4] 2> 1048731 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[3 (1436678379887656960)]} 0 0
[junit4:junit4] 2> 1048740 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[3 (1436678379892899840)]} 0 0
[junit4:junit4] 2> 1048741 T2439 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[3 (1436678379892899840)]} 0 5
[junit4:junit4] 2> 1048742 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[3]} 0 8
[junit4:junit4] 2> 1048745 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[4 (1436678379902337024)]} 0 0
[junit4:junit4] 2> 1048754 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[4 (1436678379907579904)]} 0 1
[junit4:junit4] 2> 1048754 T2425 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[4 (1436678379907579904)]} 0 4
[junit4:junit4] 2> 1048755 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[4]} 0 7
[junit4:junit4] 2> 1048757 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[5 (1436678379914919936)]} 0 0
[junit4:junit4] 2> 1048766 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[5 (1436678379920162816)]} 0 1
[junit4:junit4] 2> 1048766 T2439 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[5 (1436678379920162816)]} 0 4
[junit4:junit4] 2> 1048767 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[5]} 0 7
[junit4:junit4] 2> 1048770 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[6 (1436678379928551424)]} 0 0
[junit4:junit4] 2> 1048776 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[6 (1436678379931697152)]} 0 0
[junit4:junit4] 2> 1048777 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[6 (1436678379931697152)]} 0 4
[junit4:junit4] 2> 1048781 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[7 (1436678379939037184)]} 0 1
[junit4:junit4] 2> 1048788 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[7 (1436678379944280064)]} 0 0
[junit4:junit4] 2> 1048789 T2439 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[7 (1436678379944280064)]} 0 4
[junit4:junit4] 2> 1048790 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[7]} 0 7
[junit4:junit4] 2> 1048792 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[8 (1436678379951620096)]} 0 0
[junit4:junit4] 2> 1048802 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[8 (1436678379957911552)]} 0 1
[junit4:junit4] 2> 1048802 T2425 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[8 (1436678379957911552)]} 0 4
[junit4:junit4] 2> 1048803 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[8]} 0 8
[junit4:junit4] 2> 1048808 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[9 (1436678379967348736)]} 0 1
[junit4:junit4] 2> 1048815 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[9 (1436678379972591616)]} 0 0
[junit4:junit4] 2> 1048816 T2439 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[9 (1436678379972591616)]} 0 4
[junit4:junit4] 2> 1048817 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[9]} 0 7
[junit4:junit4] 2> 1048820 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10 (1436678379979931648)]} 0 1
[junit4:junit4] 2> 1048825 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[10 (1436678379983077376)]} 0 0
[junit4:junit4] 2> 1048826 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[10 (1436678379983077376)]} 0 4
[junit4:junit4] 2> 1048830 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[11 (1436678379990417408)]} 0 1
[junit4:junit4] 2> 1048837 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[11 (1436678379995660288)]} 0 0
[junit4:junit4] 2> 1048838 T2425 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[11 (1436678379995660288)]} 0 4
[junit4:junit4] 2> 1048839 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[11]} 0 7
[junit4:junit4] 2> 1048841 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[12 (1436678380003000320)]} 0 0
[junit4:junit4] 2> 1048850 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[12 (1436678380008243200)]} 0 1
[junit4:junit4] 2> 1048850 T2425 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[12 (1436678380008243200)]} 0 4
[junit4:junit4] 2> 1048851 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[12]} 0 7
[junit4:junit4] 2> 1048854 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[13 (1436678380016631808)]} 0 0
[junit4:junit4] 2> 1048863 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[13 (1436678380021874688)]} 0 0
[junit4:junit4] 2> 1048864 T2425 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[13 (1436678380021874688)]} 0 5
[junit4:junit4] 2> 1048865 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[13]} 0 8
[junit4:junit4] 2> 1048867 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[14 (1436678380030263296)]} 0 0
[junit4:junit4] 2> 1048875 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[14 (1436678380035506176)]} 0 0
[junit4:junit4] 2> 1048876 T2425 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[14 (1436678380035506176)]} 0 4
[junit4:junit4] 2> 1048877 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[14]} 0 7
[junit4:junit4] 2> 1048879 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[15 (1436678380042846208)]} 0 0
[junit4:junit4] 2> 1048885 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[15 (1436678380045991936)]} 0 0
[junit4:junit4] 2> 1048886 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[15 (1436678380045991936)]} 0 4
[junit4:junit4] 2> 1048890 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[16 (1436678380054380544)]} 0 0
[junit4:junit4] 2> 1048898 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[16 (1436678380058574848)]} 0 0
[junit4:junit4] 2> 1048899 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[16 (1436678380058574848)]} 0 5
[junit4:junit4] 2> 1048902 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[17 (1436678380066963456)]} 0 0
[junit4:junit4] 2> 1048911 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[17 (1436678380072206336)]} 0 1
[junit4:junit4] 2> 1048911 T2439 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[17 (1436678380072206336)]} 0 4
[junit4:junit4] 2> 1048912 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[17]} 0 7
[junit4:junit4] 2> 1048916 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[18 (1436678380081643520)]} 0 0
[junit4:junit4] 2> 1048922 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[18 (1436678380084789248)]} 0 0
[junit4:junit4] 2> 1048923 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[18 (1436678380084789248)]} 0 4
[junit4:junit4] 2> 1048927 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[19 (1436678380093177856)]} 0 0
[junit4:junit4] 2> 1048934 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[19 (1436678380097372160)]} 0 0
[junit4:junit4] 2> 1048935 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[19 (1436678380097372160)]} 0 4
[junit4:junit4] 2> 1048939 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[20 (1436678380104712192)]} 0 1
[junit4:junit4] 2> 1048947 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[20 (1436678380109955072)]} 0 1
[junit4:junit4] 2> 1048947 T2425 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[20 (1436678380109955072)]} 0 4
[junit4:junit4] 2> 1048948 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[20]} 0 7
[junit4:junit4] 2> 1048951 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[21 (1436678380118343680)]} 0 0
[junit4:junit4] 2> 1048958 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[21 (1436678380121489408)]} 0 1
[junit4:junit4] 2> 1048958 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[21 (1436678380121489408)]} 0 4
[junit4:junit4] 2> 1048961 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[22 (1436678380128829440)]} 0 0
[junit4:junit4] 2> 1048968 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[22 (1436678380133023744)]} 0 0
[junit4:junit4] 2> 1048969 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[22 (1436678380133023744)]} 0 4
[junit4:junit4] 2> 1048973 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[23 (1436678380140363776)]} 0 1
[junit4:junit4] 2> 1048978 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[23 (1436678380143509504)]} 0 0
[junit4:junit4] 2> 1048979 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[23 (1436678380143509504)]} 0 4
[junit4:junit4] 2> 1048982 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[24 (1436678380150849536)]} 0 0
[junit4:junit4] 2> 1048992 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[24 (1436678380157140992)]} 0 0
[junit4:junit4] 2> 1048993 T2425 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[24 (1436678380157140992)]} 0 5
[junit4:junit4] 2> 1048994 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[24]} 0 8
[junit4:junit4] 2> 1048997 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[25 (1436678380165529600)]} 0 1
[junit4:junit4] 2> 1049004 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[25 (1436678380169723904)]} 0 0
[junit4:junit4] 2> 1049005 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[25 (1436678380169723904)]} 0 5
[junit4:junit4] 2> 1049010 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[26 (1436678380179161088)]} 0 1
[junit4:junit4] 2> 1049016 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[26 (1436678380183355392)]} 0 0
[junit4:junit4] 2> 1049017 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[26 (1436678380183355392)]} 0 4
[junit4:junit4] 2> 1049020 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[27 (1436678380190695424)]} 0 0
[junit4:junit4] 2> 1049026 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[27 (1436678380193841152)]} 0 0
[junit4:junit4] 2> 1049027 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[27 (1436678380193841152)]} 0 4
[junit4:junit4] 2> 1049030 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[28 (1436678380201181184)]} 0 0
[junit4:junit4] 2> 1049039 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[28 (1436678380207472640)]} 0 0
[junit4:junit4] 2> 1049040 T2425 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[28 (1436678380207472640)]} 0 4
[junit4:junit4] 2> 1049041 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[28]} 0 8
[junit4:junit4] 2> 1049044 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[29 (1436678380214812672)]} 0 1
[junit4:junit4] 2> 1049052 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[29 (1436678380221104128)]} 0 0
[junit4:junit4] 2> 1049053 T2439 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[29 (1436678380221104128)]} 0 4
[junit4:junit4] 2> 1049054 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[29]} 0 8
[junit4:junit4] 2> 1049057 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[30 (1436678380229492736)]} 0 0
[junit4:junit4] 2> 1049064 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[30 (1436678380232638464)]} 0 0
[junit4:junit4] 2> 1049065 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[30 (1436678380232638464)]} 0 5
[junit4:junit4] 2> 1049069 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[31 (1436678380242075648)]} 0 0
[junit4:junit4] 2> 1049075 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[31 (1436678380245221376)]} 0 0
[junit4:junit4] 2> 1049076 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[31 (1436678380245221376)]} 0 4
[junit4:junit4] 2> 1049079 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[32 (1436678380252561408)]} 0 0
[junit4:junit4] 2> 1049090 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[32 (1436678380258852864)]} 0 0
[junit4:junit4] 2> 1049090 T2425 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[32 (1436678380258852864)]} 0 5
[junit4:junit4] 2> 1049091 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[32]} 0 8
[junit4:junit4] 2> 1049094 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[33 (1436678380268290048)]} 0 0
[junit4:junit4] 2> 1049100 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[33 (1436678380271435776)]} 0 0
[junit4:junit4] 2> 1049101 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[33 (1436678380271435776)]} 0 4
[junit4:junit4] 2> 1049104 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[34 (1436678380278775808)]} 0 0
[junit4:junit4] 2> 1049112 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[34 (1436678380284018688)]} 0 0
[junit4:junit4] 2> 1049113 T2425 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[34 (1436678380284018688)]} 0 4
[junit4:junit4] 2> 1049114 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[34]} 0 7
[junit4:junit4] 2> 1049116 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[35 (1436678380291358720)]} 0 0
[junit4:junit4] 2> 1049124 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[35 (1436678380296601600)]} 0 0
[junit4:junit4] 2> 1049125 T2425 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[35 (1436678380296601600)]} 0 4
[junit4:junit4] 2> 1049126 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[35]} 0 7
[junit4:junit4] 2> 1049130 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[36 (1436678380304990208)]} 0 1
[junit4:junit4] 2> 1049138 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[36 (1436678380311281664)]} 0 0
[junit4:junit4] 2> 1049139 T2425 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[36 (1436678380311281664)]} 0 4
[junit4:junit4] 2> 1049140 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[36]} 0 8
[junit4:junit4] 2> 1049143 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[37 (1436678380319670272)]} 0 0
[junit4:junit4] 2> 1049153 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[37 (1436678380325961728)]} 0 1
[junit4:junit4] 2> 1049153 T2439 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[37 (1436678380325961728)]} 0 4
[junit4:junit4] 2> 1049154 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[37]} 0 7
[junit4:junit4] 2> 1049156 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[38 (1436678380333301760)]} 0 0
[junit4:junit4] 2> 1049162 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[38 (1436678380336447488)]} 0 0
[junit4:junit4] 2> 1049163 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[38 (1436678380336447488)]} 0 4
[junit4:junit4] 2> 1049166 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[39 (1436678380343787520)]} 0 0
[junit4:junit4] 2> 1049175 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[39 (1436678380350078976)]} 0 0
[junit4:junit4] 2> 1049176 T2439 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[39 (1436678380350078976)]} 0 4
[junit4:junit4] 2> 1049177 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[39]} 0 7
[junit4:junit4] 2> 1049180 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[40 (1436678380358467584)]} 0 0
[junit4:junit4] 2> 1049189 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[40 (1436678380364759040)]} 0 0
[junit4:junit4] 2> 1049190 T2425 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[40 (1436678380364759040)]} 0 4
[junit4:junit4] 2> 1049191 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[40]} 0 7
[junit4:junit4] 2> 1049193 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[41 (1436678380372099072)]} 0 0
[junit4:junit4] 2> 1049199 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[41 (1436678380375244800)]} 0 0
[junit4:junit4] 2> 1049200 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[41 (1436678380375244800)]} 0 4
[junit4:junit4] 2> 1049204 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[42 (1436678380382584832)]} 0 1
[junit4:junit4] 2> 1049209 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[42 (1436678380385730560)]} 0 0
[junit4:junit4] 2> 1049210 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[42 (1436678380385730560)]} 0 4
[junit4:junit4] 2> 1049213 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[43 (1436678380393070592)]} 0 0
[junit4:junit4] 2> 1049223 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[43 (1436678380399362048)]} 0 0
[junit4:junit4] 2> 1049223 T2425 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[43 (1436678380399362048)]} 0 4
[junit4:junit4] 2> 1049224 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[43]} 0 7
[junit4:junit4] 2> 1049227 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[44 (1436678380406702080)]} 0 1
[junit4:junit4] 2> 1049232 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[44 (1436678380409847808)]} 0 0
[junit4:junit4] 2> 1049233 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[44 (1436678380409847808)]} 0 4
[junit4:junit4] 2> 1049237 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[45 (1436678380417187840)]} 0 1
[junit4:junit4] 2> 1049243 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[45 (1436678380421382144)]} 0 0
[junit4:junit4] 2> 1049244 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[45 (1436678380421382144)]} 0 4
[junit4:junit4] 2> 1049249 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[46 (1436678380429770752)]} 0 1
[junit4:junit4] 2> 1049258 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[46 (1436678380436062208)]} 0 0
[junit4:junit4] 2> 1049258 T2425 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[46 (1436678380436062208)]} 0 4
[junit4:junit4] 2> 1049259 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[46]} 0 7
[junit4:junit4] 2> 1049261 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[47 (1436678380443402240)]} 0 0
[junit4:junit4] 2> 1049267 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[47 (1436678380446547968)]} 0 0
[junit4:junit4] 2> 1049268 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[47 (1436678380446547968)]} 0 4
[junit4:junit4] 2> 1049271 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[48 (1436678380453888000)]} 0 0
[junit4:junit4] 2> 1049279 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[48 (1436678380459130880)]} 0 0
[junit4:junit4] 2> 1049280 T2425 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[48 (1436678380459130880)]} 0 4
[junit4:junit4] 2> 1049281 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[48]} 0 7
[junit4:junit4] 2> 1049283 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[49 (1436678380466470912)]} 0 0
[junit4:junit4] 2> 1049289 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[49 (1436678380469616640)]} 0 0
[junit4:junit4] 2> 1049290 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[49 (1436678380469616640)]} 0 4
[junit4:junit4] 2> 1049293 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[50 (1436678380476956672)]} 0 0
[junit4:junit4] 2> 1049299 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[50 (1436678380481150976)]} 0 0
[junit4:junit4] 2> 1049300 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[50 (1436678380481150976)]} 0 4
[junit4:junit4] 2> 1049303 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[51 (1436678380487442432)]} 0 0
[junit4:junit4] 2> 1049312 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[51 (1436678380492685312)]} 0 0
[junit4:junit4] 2> 1049313 T2425 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[51 (1436678380492685312)]} 0 5
[junit4:junit4] 2> 1049314 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[51]} 0 8
[junit4:junit4] 2> 1049316 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[52 (1436678380501073920)]} 0 0
[junit4:junit4] 2> 1049325 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[52 (1436678380506316800)]} 0 0
[junit4:junit4] 2> 1049325 T2425 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[52 (1436678380506316800)]} 0 4
[junit4:junit4] 2> 1049326 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[52]} 0 7
[junit4:junit4] 2> 1049328 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[53 (1436678380513656832)]} 0 0
[junit4:junit4] 2> 1049336 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[53 (1436678380518899712)]} 0 0
[junit4:junit4] 2> 1049337 T2439 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[53 (1436678380518899712)]} 0 4
[junit4:junit4] 2> 1049338 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[53]} 0 7
[junit4:junit4] 2> 1049340 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[54 (1436678380526239744)]} 0 0
[junit4:junit4] 2> 1049347 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[54 (1436678380529385472)]} 0 1
[junit4:junit4] 2> 1049347 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[54 (1436678380529385472)]} 0 4
[junit4:junit4] 2> 1049350 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[55 (1436678380536725504)]} 0 0
[junit4:junit4] 2> 1049357 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[55 (1436678380539871232)]} 0 1
[junit4:junit4] 2> 1049357 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[55 (1436678380539871232)]} 0 4
[junit4:junit4] 2> 1049360 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[56 (1436678380547211264)]} 0 0
[junit4:junit4] 2> 1049368 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[56 (1436678380552454144)]} 0 0
[junit4:junit4] 2> 1049369 T2439 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[56 (1436678380552454144)]} 0 4
[junit4:junit4] 2> 1049370 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[56]} 0 7
[junit4:junit4] 2> 1049372 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[57 (1436678380559794176)]} 0 0
[junit4:junit4] 2> 1049380 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[57 (1436678380565037056)]} 0 0
[junit4:junit4] 2> 1049381 T2439 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[57 (1436678380565037056)]} 0 4
[junit4:junit4] 2> 1049382 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[57]} 0 7
[junit4:junit4] 2> 1049384 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[58 (1436678380572377088)]} 0 0
[junit4:junit4] 2> 1049391 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[58 (1436678380575522816)]} 0 0
[junit4:junit4] 2> 1049391 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[58 (1436678380575522816)]} 0 4
[junit4:junit4] 2> 1049395 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[59 (1436678380582862848)]} 0 1
[junit4:junit4] 2> 1049401 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[59 (1436678380588105728)]} 0 0
[junit4:junit4] 2> 1049402 T2425 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[59 (1436678380588105728)]} 0 3
[junit4:junit4] 2> 1049403 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[59]} 0 6
[junit4:junit4] 2> 1049406 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[60 (1436678380594397184)]} 0 0
[junit4:junit4] 2> 1049412 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[60 (1436678380598591488)]} 0 0
[junit4:junit4] 2> 1049413 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[60 (1436678380598591488)]} 0 4
[junit4:junit4] 2> 1049416 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[61 (1436678380605931520)]} 0 0
[junit4:junit4] 2> 1049424 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[61 (1436678380610125824)]} 0 1
[junit4:junit4] 2> 1049424 T2423 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[61 (1436678380610125824)]} 0 4
[junit4:junit4] 2> 1049427 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[62 (1436678380617465856)]} 0 0
[junit4:junit4] 2> 1049435 T2470 C673 P51860 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[62 (1436678380620611584)]} 0 1
[junit4:junit4] 2> 1049435 T2441 C675 P25589 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[62 (1436678380620611584)]} 0 5
[junit4:junit4] 2> 1049438 T2399 C676 P59484 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={wt=javabin&version=2} {add=[63 (1436678380629000192)]} 0 0
[junit4:junit4] 2> 1049449 T2451 C672 P15430 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:18672/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[63 (1436678380635291648)]} 0 1
[junit4:junit4] 2> 1049449 T2425 C674 P18672 oasup.LogUpdateProcessor.finish [collection1] webapp= path=/update params={distrib.from=http://127.0.0.1:25589/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[63 (1436678380635291648)]} 0 5
[junit4:junit4] 2> 1049450 T2441 C675 P25589 oasup.LogUpda
[...truncated too long message...]
unit4:junit4] 2> "base_url":"http://127.0.0.1:15430"}
[junit4:junit4] 2> 1299954 T2559 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 1299954 T2478 oascc.ZkStateReader$3.process Updating live nodes... (1)
[junit4:junit4] 2> 1299954 T2478 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> 1299994 T2387 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 51860
[junit4:junit4] 2> 1299994 T2387 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1753521914
[junit4:junit4] 2> 1300997 T2387 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1300997 T2387 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1300999 T2387 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@3a661f1f
[junit4:junit4] 2> 1301001 T2387 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=850,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4:junit4] 2> 1301002 T2387 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 1301002 T2387 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 1301003 T2387 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 1301005 T2387 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 1301006 T2387 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 1301006 T2387 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty4/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty4/index;done=false>>]
[junit4:junit4] 2> 1301007 T2387 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty4/index
[junit4:junit4] 2> 1301007 T2387 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty4 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty4;done=false>>]
[junit4:junit4] 2> 1301008 T2387 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693/jetty4
[junit4:junit4] 2> 1301009 T2559 oasc.Overseer$ClusterStateUpdater.amILeader According to ZK I (id=89792397030260748-127.0.0.1:51860_-n_0000000004) am no longer a leader.
[junit4:junit4] 2> 1301010 T2478 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> 1301010 T2478 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 1301010 T2387 oejsh.ContextHandler.doStop stopped o.e.j.s.ServletContextHandler{/,null}
[junit4:junit4] 2> 1301011 T2478 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 1301080 T2387 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 1301082 T2387 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:44437 44437
[junit4:junit4] 2> 1301165 T2387 oasc.ChaosMonkey.monkeyLog monkey: stop shard! 59484
[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/J0/./org.apache.solr.cloud.ChaosMonkeyShardSplitTest-1370123245693 FAILED !!!!!
[junit4:junit4] 2> 1301166 T2387 oas.SolrTestCaseJ4.tearDown ###Ending testDistribSearch
[junit4:junit4] 2> 1301167 T2387 oasc.ZkTestServer.send4LetterWord connecting to 127.0.0.1:44437 44437
[junit4:junit4] 1> client port:0.0.0.0/0.0.0.0:0
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ChaosMonkeyShardSplitTest -Dtests.method=testDistribSearch -Dtests.seed=B14C329FC6F37C9D -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=es_UY -Dtests.timezone=America/Kentucky/Monticello -Dtests.file.encoding=UTF-8
[junit4:junit4] ERROR 279s J0 | ChaosMonkeyShardSplitTest.testDistribSearch <<<
[junit4:junit4] > Throwable #1: org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:18672 returned non ok status:500, message:Server Error
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([B14C329FC6F37C9D:30AABC87B1AC1CA1]: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:208)
[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> 1301195 T2387 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 278616 T2386 ccr.ThreadLeakControl.checkThreadLeaks WARNING Will linger awaiting termination of 2 leaked thread(s).
[junit4:junit4] 2> 1301241 T2461 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 1301241 T2461 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> 1301241 T2461 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 1301241 T2461 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> NOTE: test params are: codec=DummyCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=DUMMY, chunkSize=331), termVectorsFormat=CompressingTermVectorsFormat(compressionMode=DUMMY, chunkSize=331)), sim=RandomSimilarityProvider(queryNorm=false,coord=yes): {}, locale=es_UY, timezone=America/Kentucky/Monticello
[junit4:junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Oracle Corporation 1.7.0_21 (64-bit)/cpus=16,threads=2,free=245104720,total=335544320
[junit4:junit4] 2> NOTE: All tests run in this JVM: [DistributedSpellCheckComponentTest, SolrCoreCheckLockOnStartupTest, ShardRoutingTest, ScriptEngineTest, TestPerFieldSimilarity, NotRequiredUniqueKeyTest, FieldAnalysisRequestHandlerTest, TestUpdate, TestQuerySenderListener, TestDocumentBuilder, BasicZkTest, SliceStateTest, CurrencyFieldOpenExchangeTest, TestFieldCollectionResource, TestIndexingPerformance, DistributedTermsComponentTest, TestLMDirichletSimilarityFactory, TestPluginEnable, SuggesterTest, BadIndexSchemaTest, TestSchemaResource, IndexReaderFactoryTest, TestCollationField, AliasIntegrationTest, TestIndexSearcher, CurrencyFieldXmlFileTest, BadCopyFieldTest, TestNumberUtils, TestLRUCache, TestBadConfig, DateFieldTest, NoCacheHeaderTest, MBeansHandlerTest, TestReplicationHandler, TestUtils, TestHashPartitioner, QueryEqualityTest, TestFiltering, SchemaVersionSpecificBehaviorTest, TestPHPSerializedResponseWriter, DistanceFunctionTest, TestMaxScoreQueryParser, SortByFunctionTest, CacheHeaderTest, TestSchemaVersionResource, TestSolrCoreProperties, LeaderElectionIntegrationTest, ShowFileRequestHandlerTest, LukeRequestHandlerTest, SolrTestCaseJ4Test, DocValuesTest, MultiTermTest, AutoCommitTest, TestPostingsSolrHighlighter, TestArbitraryIndexDir, TestSweetSpotSimilarityFactory, TestRemoteStreaming, DisMaxRequestHandlerTest, CollectionsAPIDistributedZkTest, TestWriterPerf, TestSolrJ, DirectSolrConnectionTest, StandardRequestHandlerTest, TestFuzzyAnalyzedSuggestions, HardAutoCommitTest, TestBM25SimilarityFactory, QueryResultKeyTest, AlternateDirectoryTest, CSVRequestHandlerTest, TestDistributedSearch, BasicFunctionalityTest, ChaosMonkeyShardSplitTest]
[junit4:junit4] Completed on J0 in 279.40s, 1 test, 1 error <<< FAILURES!
[...truncated 450 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:386: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java7/build.xml:366: 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, 1238 tests, 1 error, 13 ignored (7 assumptions)
Total time: 52 minutes 2 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure