lucene-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Apache Jenkins Server <jenk...@builds.apache.org>
Subject [JENKINS] Lucene-Solr-Tests-4.x-java7 - Build # 1088 - Still Failing
Date Fri, 22 Mar 2013 01:49:23 GMT
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-java7/1088/

2 tests failed.
REGRESSION:  org.apache.solr.update.SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete

Error Message:
searcher529 wasn't soon enough after soft529: 1363915574324 !< 1363915574205 + 100 (fudge)

Stack Trace:
java.lang.AssertionError: searcher529 wasn't soon enough after soft529: 1363915574324 !< 1363915574205 + 100 (fudge)
	at __randomizedtesting.SeedInfo.seed([9A03EFD7AD17965C:5D4F574AB6BF5BEC]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at org.apache.solr.update.SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete(SoftAutoCommitTest.java:265)
	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)


FAILED:  org.apache.solr.cloud.SyncSliceTest.testDistribSearch

Error Message:
Test Setup Failure: shard1 should have just been set up to be inconsistent - but it's still consistent. Leader:http://127.0.0.1:29291/collection1 Dead Guy:http://127.0.0.1:29281/collection1skip list:[CloudJettyRunner [url=http://127.0.0.1:29310/collection1], CloudJettyRunner [url=http://127.0.0.1:29310/collection1]]

Stack Trace:
java.lang.AssertionError: Test Setup Failure: shard1 should have just been set up to be inconsistent - but it's still consistent. Leader:http://127.0.0.1:29291/collection1 Dead Guy:http://127.0.0.1:29281/collection1skip list:[CloudJettyRunner [url=http://127.0.0.1:29310/collection1], CloudJettyRunner [url=http://127.0.0.1:29310/collection1]]
	at __randomizedtesting.SeedInfo.seed([9A03EFD7AD17965C:1BE561CFDA48F660]:0)
	at org.junit.Assert.fail(Assert.java:93)
	at org.junit.Assert.assertTrue(Assert.java:43)
	at org.junit.Assert.assertNotNull(Assert.java:526)
	at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:212)
	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:806)
	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 9034 lines...]
[junit4:junit4] Suite: org.apache.solr.update.SoftAutoCommitTest
[junit4:junit4]   2> 0 T113 oas.SolrTestCaseJ4.startTrackingSearchers WARNING startTrackingSearchers: numOpens=2 numCloses=2
[junit4:junit4]   2> 2 T113 oas.SolrTestCaseJ4.initCore ####initCore
[junit4:junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./solrtest-SoftAutoCommitTest-1363915571369
[junit4:junit4]   2> 2 T113 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 4 T113 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 4 T113 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 90 T113 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_43
[junit4:junit4]   2> 196 T113 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 197 T113 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 210 T113 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 834 T113 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 846 T113 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 849 T113 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 866 T113 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 872 T113 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 876 T113 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 877 T113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 878 T113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 878 T113 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 879 T113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 879 T113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 880 T113 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 880 T113 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-files/solr
[junit4:junit4]   2> 880 T113 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/'
[junit4:junit4]   2> 893 T113 oasc.CoreContainer.<init> New CoreContainer 1085112373
[junit4:junit4]   2> 894 T113 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 895 T113 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-files/solr/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./solrtest-SoftAutoCommitTest-1363915571369/
[junit4:junit4]   2> 895 T113 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2299e3c9
[junit4:junit4]   2> 896 T113 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4]   2> 896 T113 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./solrtest-SoftAutoCommitTest-1363915571369
[junit4:junit4]   2> 897 T113 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./solrtest-SoftAutoCommitTest-1363915571369/index/
[junit4:junit4]   2> 897 T113 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./solrtest-SoftAutoCommitTest-1363915571369/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 899 T113 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./solrtest-SoftAutoCommitTest-1363915571369/index
[junit4:junit4]   2> 904 T113 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/index3941139413tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@2d7f6d79)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 905 T113 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 906 T113 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 908 T113 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 909 T113 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 909 T113 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 910 T113 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 910 T113 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 911 T113 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 911 T113 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 912 T113 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 912 T113 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 913 T113 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 914 T113 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 914 T113 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 915 T113 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 915 T113 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 915 T113 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 916 T113 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 917 T113 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 917 T113 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 918 T113 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 918 T113 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 919 T113 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 920 T113 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 920 T113 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 921 T113 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 921 T113 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 922 T113 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 933 T113 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 939 T113 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 941 T113 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [THROW.ERROR.ON.ADD.UPDATEPROCESSOR.JS, SOLRCONFIG-HIGHLIGHT.XML, SCHEMA-REQUIRED-FIELDS.XML, BAD-SCHEMA-DOCVALUES-NOT-REQUIRED-NO-DEFAULT.XML, SCHEMA-MINIMAL.XML, BAD-SCHEMA-DUP-DYNAMICFIELD.XML, SCHEMA-REPLICATION2.XML, TRIVIAL.UPDATEPROCESSOR1.JS, SOLRCONFIG-CACHING.XML, SCHEMA-POSTINGSHIGHLIGHT.XML, REGEX-BOOST-PROCESSOR-TEST.TXT, SOLRCONFIG-REPEATER.XML, BAD-SCHEMA-CURRENCY-FT-BOGUS-CODE-IN-XML.XML, BAD-SCHEMA-NONTEXT-ANALYZER.XML, CURRENCY.XML, SOLRCONFIG-MERGEPOLICY.XML, SOLRCONFIG-TLOG.XML, SOLRCONFIG-MASTER.XML, SOLRCONFIG-COMPONENTS-NAME.XML, BAD-SCHEMA-UNIQUEKEY-MULTIVALUED.XML, SCHEMA11.XML, SOLRCONFIG-BASIC.XML, DA_COMPOUNDDICTIONARY.TXT, MISSLEADING.EXTENSION.UPDATEPROCESSOR.JS.TXT, SCHEMA-COPYFIELD-TEST.XML, SOLRCONFIG-SLAVE.XML, ELEVATE.XML, SOLRCONFIG-PROPINJECT-INDEXDEFAULT.XML, TRIVIAL.UPDATEPROCESSOR0.JS, SCHEMA-SWEETSPOT.XML, BAD-SOLRCONFIG-BOGUS-SCRIPTENGINE-NAME.XML, SCHEMA-CHARFILTERS.XML, SCHEMA-IB.XML, SOLRCONFIG-QUERYSENDER.XML, SOLRCONFIG-SNIPPET-PROCESSOR.XML, SCHEMA-REPLICATION1.XML, DA_UTF8.XML, SCHEMA-TINY.XML, CONDITIONAL.UPDATEPROCESSOR.JS, MISSING.FUNCTIONS.UPDATEPROCESSOR.JS, HYPHENATION.DTD, SOLRCONFIG-ENABLEPLUGIN.XML, STEMDICT.TXT, SCHEMA-PHRASESUGGEST.XML, HUNSPELL-TEST.AFF, BAD-SCHEMA-CURRENCY-FT-OER-NORATES.XML, SCHEMA-SNIPPET-TYPE.XML, STOPTYPES-1.TXT, STOPWORDSWRONGENCODING.TXT, SCHEMA-NUMERIC.XML, SOLRCONFIG-TRANSFORMERS.XML, SOLRCONFIG-PROPINJECT.XML, BAD-SCHEMA-NOT-INDEXED-BUT-TF.XML, SOLRCONFIG-SIMPLELOCK.XML, SCHEMA-DOCVALUES.XML, WDFTYPES.TXT, STOPTYPES-2.TXT, SCHEMA-REVERSED.XML, BAD-SCHEMA-CURRENCY-FT-MULTIVALUED.XML, SOLRCONFIG-SPELLCHECKCOMPONENT.XML, SOLRCONFIG-PHRASESUGGEST.XML, SCHEMA-DFR.XML, BAD-SCHEMA-CURRENCY-MULTIVALUED.XML, BAD-SCHEMA-NOT-INDEXED-BUT-POS.XML, KEEP-1.TXT, OPEN-EXCHANGE-RATES.JSON, SCHEMA-SPATIAL.XML, STOPWITHBOM.TXT, SOLRCONFIG-POSTINGSHIGHLIGHT.XML, SCHEMA-BINARYFIELD.XML, SOLRCONFIG-SPELLCHECKER.XML, SOLRCONFIG-UPDATE-PROCESSOR-CHAINS.XML, BAD-SCHEMA-OMIT-TF-BUT-NOT-POS.XML, SCHEMA-XINCLUDE.XML, BAD-SCHEMA-DUP-FIELDTYPE.XML, SOLRCONFIG-MASTER1.XML, SCHEMA-BEHAVIOR.XML, SYNONYMS.TXT, SOLRCONFIG-MINIMAL.XML, SCHEMA-DOCVALUESMULTI.XML, BAD-SCHEMA-UNSUPPORTED-DOCVALUES.XML, BAD-SCHEMA-CURRENCY-DYNAMIC-MULTIVALUED.XML, SCHEMA_CODEC.XML, BAD-SCHEMA-SWEETSPOT-PARTIAL-HYPERBOLIC.XML, SOLRCONFIG-SOLR-749.XML, SOLRCONFIG-MASTER1-KEEPONEBACKUP.XML, SCHEMA-EFF.XML, STOP-2.TXT, SOLRCONFIG-FUNCTIONQUERY.XML, SCHEMA-LMDIRICHLET.XML, SOLRCONFIG-TERMINDEX.XML, SOLRCONFIG-ELEVATE.XML, BAD-SCHEMA-SWEETSPOT-PARTIAL-NORMS.XML, BAD-SCHEMA-SWEETSPOT-PARTIAL-BASELINE.XML, STOPWORDS.TXT, SCHEMA-FOLDING.XML, SCHEMA-STOP-KEEP.XML, FUZZYSUGGEST.TXT, BAD-SCHEMA-NOT-INDEXED-BUT-NORMS.XML, SCHEMA-REST.XML, SOLRCONFIG-SOLCOREPROPERTIES.XML, STOP-1.TXT, SOLRCONFIG-MASTER2.XML, SCHEMA-SPELLCHECKER.XML, SOLRCONFIG-RESPONSE-LOG-COMPONENT.XML, SOLRCONFIG-LAZYWRITER.XML, SCHEMA-LUCENEMATCHVERSION.XML, BAD-MP-SOLRCONFIG.XML, FRENCHARTICLES.TXT, SCHEMA15.XML, SOLRCONFIG-REQHANDLER.INCL, SCHEMASURROUND.XML, SCHEMA-COLLATEFILTER.XML, SOLRCONFIG-MASTER3.XML, HUNSPELL-TEST.DIC, SOLRCONFIG-XINCLUDE.XML, BAD-SCHEMA-CODEC-GLOBAL-VS-FT-MISMATCH.XML, SOLRCONFIG-SLAVE1.XML, SOLRCONFIG-DELPOLICY1.XML, SCHEMA-SIM.XML, SCHEMA-SNIPPET-FIELD.XML, SCHEMA-COLLATE.XML, STOP-SNOWBALL.TXT, BAD-SCHEMA-SIM-GLOBAL-VS-FT-MISMATCH.XML, PROTWORDS.TXT, SCHEMA-TRIE.XML, SOLRCONFIG_CODEC.XML, SCHEMA-SYNONYM-TOKENIZER.XML, BAD-SOLRCONFIG-INVALID-SCRIPTFILE.XML, JASUGGEST.TXT, SCHEMA-DOCVALUESFACETING.XML, SCHEMA-TFIDF.XML, SOLRCONFIG-SCRIPT-UPDATEPROCESSOR.XML, SCHEMA-LMJELINEKMERCER.XML, PHRASESUGGEST.TXT, BAD-SOLRCONFIG-MISSING-SCRIPTFILE.XML, SOLRCONFIG-BASIC-LUCENEVERSION31.XML, BAD-SCHEMA-UNIQUEKEY-USES-DEFAULT.XML, OLD_SYNONYMS.TXT, SOLRCONFIG-DELPOLICY2.XML, SOLRCONFIG-NATIVELOCK.XML, XSLT, BAD-SCHEMA-DUP-FIELD.XML, SOLRCONFIG-NOCACHE.XML, SCHEMA-BM25.XML, BAD-SCHEMA-SWEETSPOT-BOTH-TF.XML, ADDFIELDS.UPDATEPROCESSOR.JS, SOLRCONFIG-ALTDIRECTORY.XML, SOLRCONFIG-QUERYSENDER-NOQUERY.XML, COMPOUNDDICTIONARY.TXT, SOLRCONFIG-INDEXCONFIG.XML, SOLRCONFIG_PERF.XML, BAD-CURRENCY.XML, BAD-SCHEMA-CURRENCY-FT-BOGUS-DEFAULT-CODE.XML, BAD-SCHEMA-ANALYZER-CLASS-AND-NESTED.XML, SCHEMA-NOT-REQUIRED-UNIQUE-KEY.XML, KEEP-2.TXT, SCHEMA12.XML, BAD-SCHEMA-UNIQUEKEY-IS-COPYFIELD-DEST.XML, MAPPING-ISOLATIN1ACCENT.TXT, BAD_SOLRCONFIG.XML, BAD-SCHEMA-EXTERNAL-FILEFIELD.XML]
[junit4:junit4]   2> 945 T113 oass.SolrIndexSearcher.<init> Opening Searcher@553396b0 main
[junit4:junit4]   2> 946 T113 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 947 T113 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 947 T113 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 953 T113 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 1063 T114 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@553396b0 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1084 T113 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 1098 T113 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4:junit4]   2> 1103 T113 oas.SolrTestCaseJ4.setUp ###Starting testSoftAndHardCommitMaxTimeDelete
[junit4:junit4]   2> 1104 T113 oasc.CoreContainer.reload Reloading SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 1105 T113 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 1106 T113 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 1107 T113 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 1197 T113 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_43
[junit4:junit4]   2> 1280 T113 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 1282 T113 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 1297 T113 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 1984 T113 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 2000 T113 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 2004 T113 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 2026 T113 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2033 T113 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 2038 T113 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2039 T113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 2039 T113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 2040 T113 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 2041 T113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 2041 T113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 2042 T113 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-files/solr/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./solrtest-SoftAutoCommitTest-1363915571369/
[junit4:junit4]   2> 2043 T113 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2299e3c9
[junit4:junit4]   2> 2044 T113 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./solrtest-SoftAutoCommitTest-1363915571369/index/
[junit4:junit4]   2> 2044 T113 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 2047 T113 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 2048 T113 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 2049 T113 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 2049 T113 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 2050 T113 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 2051 T113 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 2051 T113 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 2053 T113 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 2054 T113 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 2055 T113 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 2056 T113 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 2056 T113 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 2057 T113 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 2058 T113 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 2059 T113 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 2060 T113 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 2061 T113 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2062 T113 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2063 T113 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2064 T113 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2065 T113 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2066 T113 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2067 T113 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2068 T113 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 2069 T113 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 2070 T113 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 2072 T113 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 2074 T113 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 2077 T113 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [THROW.ERROR.ON.ADD.UPDATEPROCESSOR.JS, SOLRCONFIG-HIGHLIGHT.XML, SCHEMA-REQUIRED-FIELDS.XML, BAD-SCHEMA-DOCVALUES-NOT-REQUIRED-NO-DEFAULT.XML, SCHEMA-MINIMAL.XML, BAD-SCHEMA-DUP-DYNAMICFIELD.XML, SCHEMA-REPLICATION2.XML, TRIVIAL.UPDATEPROCESSOR1.JS, SOLRCONFIG-CACHING.XML, SCHEMA-POSTINGSHIGHLIGHT.XML, REGEX-BOOST-PROCESSOR-TEST.TXT, SOLRCONFIG-REPEATER.XML, BAD-SCHEMA-CURRENCY-FT-BOGUS-CODE-IN-XML.XML, BAD-SCHEMA-NONTEXT-ANALYZER.XML, CURRENCY.XML, SOLRCONFIG-MERGEPOLICY.XML, SOLRCONFIG-TLOG.XML, SOLRCONFIG-MASTER.XML, SOLRCONFIG-COMPONENTS-NAME.XML, BAD-SCHEMA-UNIQUEKEY-MULTIVALUED.XML, SCHEMA11.XML, SOLRCONFIG-BASIC.XML, DA_COMPOUNDDICTIONARY.TXT, MISSLEADING.EXTENSION.UPDATEPROCESSOR.JS.TXT, SCHEMA-COPYFIELD-TEST.XML, SOLRCONFIG-SLAVE.XML, ELEVATE.XML, SOLRCONFIG-PROPINJECT-INDEXDEFAULT.XML, TRIVIAL.UPDATEPROCESSOR0.JS, SCHEMA-SWEETSPOT.XML, BAD-SOLRCONFIG-BOGUS-SCRIPTENGINE-NAME.XML, SCHEMA-CHARFILTERS.XML, SCHEMA-IB.XML, SOLRCONFIG-QUERYSENDER.XML, SOLRCONFIG-SNIPPET-PROCESSOR.XML, SCHEMA-REPLICATION1.XML, DA_UTF8.XML, SCHEMA-TINY.XML, CONDITIONAL.UPDATEPROCESSOR.JS, MISSING.FUNCTIONS.UPDATEPROCESSOR.JS, HYPHENATION.DTD, SOLRCONFIG-ENABLEPLUGIN.XML, STEMDICT.TXT, SCHEMA-PHRASESUGGEST.XML, HUNSPELL-TEST.AFF, BAD-SCHEMA-CURRENCY-FT-OER-NORATES.XML, SCHEMA-SNIPPET-TYPE.XML, STOPTYPES-1.TXT, STOPWORDSWRONGENCODING.TXT, SCHEMA-NUMERIC.XML, SOLRCONFIG-TRANSFORMERS.XML, SOLRCONFIG-PROPINJECT.XML, BAD-SCHEMA-NOT-INDEXED-BUT-TF.XML, SOLRCONFIG-SIMPLELOCK.XML, SCHEMA-DOCVALUES.XML, WDFTYPES.TXT, STOPTYPES-2.TXT, SCHEMA-REVERSED.XML, BAD-SCHEMA-CURRENCY-FT-MULTIVALUED.XML, SOLRCONFIG-SPELLCHECKCOMPONENT.XML, SOLRCONFIG-PHRASESUGGEST.XML, SCHEMA-DFR.XML, BAD-SCHEMA-CURRENCY-MULTIVALUED.XML, BAD-SCHEMA-NOT-INDEXED-BUT-POS.XML, KEEP-1.TXT, OPEN-EXCHANGE-RATES.JSON, SCHEMA-SPATIAL.XML, STOPWITHBOM.TXT, SOLRCONFIG-POSTINGSHIGHLIGHT.XML, SCHEMA-BINARYFIELD.XML, SOLRCONFIG-SPELLCHECKER.XML, SOLRCONFIG-UPDATE-PROCESSOR-CHAINS.XML, BAD-SCHEMA-OMIT-TF-BUT-NOT-POS.XML, SCHEMA-XINCLUDE.XML, BAD-SCHEMA-DUP-FIELDTYPE.XML, SOLRCONFIG-MASTER1.XML, SCHEMA-BEHAVIOR.XML, SYNONYMS.TXT, SOLRCONFIG-MINIMAL.XML, SCHEMA-DOCVALUESMULTI.XML, BAD-SCHEMA-UNSUPPORTED-DOCVALUES.XML, BAD-SCHEMA-CURRENCY-DYNAMIC-MULTIVALUED.XML, SCHEMA_CODEC.XML, BAD-SCHEMA-SWEETSPOT-PARTIAL-HYPERBOLIC.XML, SOLRCONFIG-SOLR-749.XML, SOLRCONFIG-MASTER1-KEEPONEBACKUP.XML, SCHEMA-EFF.XML, STOP-2.TXT, SOLRCONFIG-FUNCTIONQUERY.XML, SCHEMA-LMDIRICHLET.XML, SOLRCONFIG-TERMINDEX.XML, SOLRCONFIG-ELEVATE.XML, BAD-SCHEMA-SWEETSPOT-PARTIAL-NORMS.XML, BAD-SCHEMA-SWEETSPOT-PARTIAL-BASELINE.XML, STOPWORDS.TXT, SCHEMA-FOLDING.XML, SCHEMA-STOP-KEEP.XML, FUZZYSUGGEST.TXT, BAD-SCHEMA-NOT-INDEXED-BUT-NORMS.XML, SCHEMA-REST.XML, SOLRCONFIG-SOLCOREPROPERTIES.XML, STOP-1.TXT, SOLRCONFIG-MASTER2.XML, SCHEMA-SPELLCHECKER.XML, SOLRCONFIG-RESPONSE-LOG-COMPONENT.XML, SOLRCONFIG-LAZYWRITER.XML, SCHEMA-LUCENEMATCHVERSION.XML, BAD-MP-SOLRCONFIG.XML, FRENCHARTICLES.TXT, SCHEMA15.XML, SOLRCONFIG-REQHANDLER.INCL, SCHEMASURROUND.XML, SCHEMA-COLLATEFILTER.XML, SOLRCONFIG-MASTER3.XML, HUNSPELL-TEST.DIC, SOLRCONFIG-XINCLUDE.XML, BAD-SCHEMA-CODEC-GLOBAL-VS-FT-MISMATCH.XML, SOLRCONFIG-SLAVE1.XML, SOLRCONFIG-DELPOLICY1.XML, SCHEMA-SIM.XML, SCHEMA-SNIPPET-FIELD.XML, SCHEMA-COLLATE.XML, STOP-SNOWBALL.TXT, BAD-SCHEMA-SIM-GLOBAL-VS-FT-MISMATCH.XML, PROTWORDS.TXT, SCHEMA-TRIE.XML, SOLRCONFIG_CODEC.XML, SCHEMA-SYNONYM-TOKENIZER.XML, BAD-SOLRCONFIG-INVALID-SCRIPTFILE.XML, JASUGGEST.TXT, SCHEMA-DOCVALUESFACETING.XML, SCHEMA-TFIDF.XML, SOLRCONFIG-SCRIPT-UPDATEPROCESSOR.XML, SCHEMA-LMJELINEKMERCER.XML, PHRASESUGGEST.TXT, BAD-SOLRCONFIG-MISSING-SCRIPTFILE.XML, SOLRCONFIG-BASIC-LUCENEVERSION31.XML, BAD-SCHEMA-UNIQUEKEY-USES-DEFAULT.XML, OLD_SYNONYMS.TXT, SOLRCONFIG-DELPOLICY2.XML, SOLRCONFIG-NATIVELOCK.XML, XSLT, BAD-SCHEMA-DUP-FIELD.XML, SOLRCONFIG-NOCACHE.XML, SCHEMA-BM25.XML, BAD-SCHEMA-SWEETSPOT-BOTH-TF.XML, ADDFIELDS.UPDATEPROCESSOR.JS, SOLRCONFIG-ALTDIRECTORY.XML, SOLRCONFIG-QUERYSENDER-NOQUERY.XML, COMPOUNDDICTIONARY.TXT, SOLRCONFIG-INDEXCONFIG.XML, SOLRCONFIG_PERF.XML, BAD-CURRENCY.XML, BAD-SCHEMA-CURRENCY-FT-BOGUS-DEFAULT-CODE.XML, BAD-SCHEMA-ANALYZER-CLASS-AND-NESTED.XML, SCHEMA-NOT-REQUIRED-UNIQUE-KEY.XML, KEEP-2.TXT, SCHEMA12.XML, BAD-SCHEMA-UNIQUEKEY-IS-COPYFIELD-DEST.XML, MAPPING-ISOLATIN1ACCENT.TXT, BAD_SOLRCONFIG.XML, BAD-SCHEMA-EXTERNAL-FILEFIELD.XML]
[junit4:junit4]   2> 2082 T113 oass.SolrIndexSearcher.<init> Opening Searcher@303e683f main
[junit4:junit4]   2> 2083 T113 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 2084 T113 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 2085 T113 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 2088 T113 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 2109 T115 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@303e683f main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 2120 T113 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 2121 T113 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 2125 T113 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/index3941139413tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@2d7f6d79)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 2125 T113 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 2126 T113 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 2127 T113 oass.SolrIndexSearcher.<init> Opening Searcher@ca2394c main
[junit4:junit4]   2> 2128 T113 oasc.CoreContainer.registerCore replacing core: collection1
[junit4:junit4]   2> 2128 T113 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@3ebc38bf
[junit4:junit4]   2> 2130 T115 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@ca2394c main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4:junit4]   2> 2138 T113 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 2139 T113 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> ASYNC  NEW_CORE C4 name=collection1 org.apache.solr.core.SolrCore@3d8fe9b5
[junit4:junit4]   2> 2153 T113 C4 UPDATE [collection1] webapp=null path=null params={} {add=[529]} 0 5
[junit4:junit4]   2> 2167 T113 C4 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 2230 T113 C4 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/index3941139413tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@2d7f6d79)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/index3941139413tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@2d7f6d79)),segFN=segments_2,generation=2,filenames=[_0.fnm, _0.pos, _0.tim, _0.nvd, segments_2, _0.fdx, _0.si, _0.nvm, _0.doc, _0.tip, _0.fdt]
[junit4:junit4]   2> 2231 T113 C4 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[_0.fnm, _0.pos, _0.tim, _0.nvd, segments_2, _0.fdx, _0.si, _0.nvm, _0.doc, _0.tip, _0.fdt]
[junit4:junit4]   2> 2323 T113 C4 oass.SolrIndexSearcher.<init> Opening Searcher@3b3a0d10 main
[junit4:junit4]   2> 2323 T113 C4 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 2325 T115 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3b3a0d10 main{StandardDirectoryReader(segments_2:3:nrt _0(4.3):C1)}
[junit4:junit4]   2> 2326 T113 C4 UPDATE [collection1] webapp=null path=null params={} {commit=} 0 159
[junit4:junit4]   2> 2335 T113 C4 UPDATE [collection1] webapp=null path=null params={} {delete=[529]} 0 0
[junit4:junit4]   2> 2838 T117 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4:junit4]   2> 2957 T117 oass.SolrIndexSearcher.<init> Opening Searcher@7f6e8cd main
[junit4:junit4]   2> 2957 T117 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 2959 T115 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7f6e8cd main{StandardDirectoryReader(segments_2:5:nrt)}
[junit4:junit4]   2> 2970 T113 C4 UPDATE [collection1] webapp=null path=null params={} {add=[550]} 0 4
[junit4:junit4]   2> 3471 T117 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4:junit4]   2> 3512 T117 oass.SolrIndexSearcher.<init> Opening Searcher@7a456c2b main
[junit4:junit4]   2> 3513 T117 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 3514 T115 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7a456c2b main{StandardDirectoryReader(segments_2:7:nrt _1(4.3):C1)}
[junit4:junit4]   2> 3548 T116 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 3584 T116 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/index3941139413tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@2d7f6d79)),segFN=segments_2,generation=2,filenames=[_0.fnm, _0.pos, _0.tim, _0.nvd, segments_2, _0.fdx, _0.si, _0.nvm, _0.doc, _0.tip, _0.fdt]
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/index3941139413tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@2d7f6d79)),segFN=segments_3,generation=3,filenames=[_1.doc, _1.fdx, _1.nvm, _1.fdt, _1.pos, _1.si, _1.nvd, _1.tip, _1.fnm, _1.tim, segments_3]
[junit4:junit4]   2> 3585 T116 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[_1.doc, _1.fdx, _1.nvm, _1.fdt, _1.pos, _1.si, _1.nvd, _1.tip, _1.fnm, _1.tim, segments_3]
[junit4:junit4]   2> 3589 T116 oass.SolrIndexSearcher.<init> Opening Searcher@49274416 main
[junit4:junit4]   2> 3589 T113 oas.SolrTestCaseJ4.tearDown ###Ending testSoftAndHardCommitMaxTimeDelete
[junit4:junit4]   2> 3589 T116 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 3591 T115 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@49274416 main{StandardDirectoryReader(segments_2:7:nrt _1(4.3):C1)}
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=SoftAutoCommitTest -Dtests.method=testSoftAndHardCommitMaxTimeDelete -Dtests.seed=9A03EFD7AD17965C -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=pt_BR -Dtests.timezone=Antarctica/Syowa -Dtests.file.encoding=ISO-8859-1
[junit4:junit4] FAILURE 2.73s J0 | SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete <<<
[junit4:junit4]    > Throwable #1: java.lang.AssertionError: searcher529 wasn't soon enough after soft529: 1363915574324 !< 1363915574205 + 100 (fudge)
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([9A03EFD7AD17965C:5D4F574AB6BF5BEC]:0)
[junit4:junit4]    > 	at org.junit.Assert.fail(Assert.java:93)
[junit4:junit4]    > 	at org.junit.Assert.assertTrue(Assert.java:43)
[junit4:junit4]    > 	at org.apache.solr.update.SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete(SoftAutoCommitTest.java:265)
[junit4:junit4]    > 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4:junit4]    > 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4:junit4]    > 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4:junit4]    > 	at java.lang.reflect.Method.invoke(Method.java:601)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[junit4:junit4]    > 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]    > 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]    > 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 3861 T113 oas.SolrTestCaseJ4.setUp ###Starting testSoftAndHardCommitMaxTimeMixedAdds
[junit4:junit4]   2> 3861 T113 oasc.CoreContainer.reload Reloading SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 3862 T113 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 3863 T113 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 3864 T113 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 3946 T113 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_43
[junit4:junit4]   2> 4003 T113 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 4004 T113 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 4013 T113 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 4665 T113 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 4677 T113 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 4681 T113 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 4697 T113 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 4702 T113 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 4706 T113 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 4707 T113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 4708 T113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 4708 T113 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 4709 T113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 4709 T113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 4710 T113 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-files/solr/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./solrtest-SoftAutoCommitTest-1363915571369/
[junit4:junit4]   2> 4710 T113 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2299e3c9
[junit4:junit4]   2> 4711 T113 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./solrtest-SoftAutoCommitTest-1363915571369/index/
[junit4:junit4]   2> 4711 T113 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 4713 T113 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 4714 T113 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 4714 T113 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 4715 T113 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 4715 T113 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 4716 T113 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 4716 T113 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 4717 T113 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 4717 T113 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 4718 T113 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 4719 T113 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 4719 T113 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 4720 T113 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 4720 T113 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 4721 T113 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 4722 T113 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 4722 T113 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4723 T113 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4724 T113 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4725 T113 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4726 T113 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4727 T113 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4728 T113 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4729 T113 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 4730 T113 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 4731 T113 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 4742 T113 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 4744 T113 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 4746 T113 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [THROW.ERROR.ON.ADD.UPDATEPROCESSOR.JS, SOLRCONFIG-HIGHLIGHT.XML, SCHEMA-REQUIRED-FIELDS.XML, BAD-SCHEMA-DOCVALUES-NOT-REQUIRED-NO-DEFAULT.XML, SCHEMA-MINIMAL.XML, BAD-SCHEMA-DUP-DYNAMICFIELD.XML, SCHEMA-REPLICATION2.XML, TRIVIAL.UPDATEPROCESSOR1.JS, SOLRCONFIG-CACHING.XML, SCHEMA-POSTINGSHIGHLIGHT.XML, REGEX-BOOST-PROCESSOR-TEST.TXT, SOLRCONFIG-REPEATER.XML, BAD-SCHEMA-CURRENCY-FT-BOGUS-CODE-IN-XML.XML, BAD-SCHEMA-NONTEXT-ANALYZER.XML, CURRENCY.XML, SOLRCONFIG-MERGEPOLICY.XML, SOLRCONFIG-TLOG.XML, SOLRCONFIG-MASTER.XML, SOLRCONFIG-COMPONENTS-NAME.XML, BAD-SCHEMA-UNIQUEKEY-MULTIVALUED.XML, SCHEMA11.XML, SOLRCONFIG-BASIC.XML, DA_COMPOUNDDICTIONARY.TXT, MISSLEADING.EXTENSION.UPDATEPROCESSOR.JS.TXT, SCHEMA-COPYFIELD-TEST.XML, SOLRCONFIG-SLAVE.XML, ELEVATE.XML, SOLRCONFIG-PROPINJECT-INDEXDEFAULT.XML, TRIVIAL.UPDATEPROCESSOR0.JS, SCHEMA-SWEETSPOT.XML, BAD-SOLRCONFIG-BOGUS-SCRIPTENGINE-NAME.XML, SCHEMA-CHARFILTERS.XML, SCHEMA-IB.XML, SOLRCONFIG-QUERYSENDER.XML, SOLRCONFIG-SNIPPET-PROCESSOR.XML, SCHEMA-REPLICATION1.XML, DA_UTF8.XML, SCHEMA-TINY.XML, CONDITIONAL.UPDATEPROCESSOR.JS, MISSING.FUNCTIONS.UPDATEPROCESSOR.JS, HYPHENATION.DTD, SOLRCONFIG-ENABLEPLUGIN.XML, STEMDICT.TXT, SCHEMA-PHRASESUGGEST.XML, HUNSPELL-TEST.AFF, BAD-SCHEMA-CURRENCY-FT-OER-NORATES.XML, SCHEMA-SNIPPET-TYPE.XML, STOPTYPES-1.TXT, STOPWORDSWRONGENCODING.TXT, SCHEMA-NUMERIC.XML, SOLRCONFIG-TRANSFORMERS.XML, SOLRCONFIG-PROPINJECT.XML, BAD-SCHEMA-NOT-INDEXED-BUT-TF.XML, SOLRCONFIG-SIMPLELOCK.XML, SCHEMA-DOCVALUES.XML, WDFTYPES.TXT, STOPTYPES-2.TXT, SCHEMA-REVERSED.XML, BAD-SCHEMA-CURRENCY-FT-MULTIVALUED.XML, SOLRCONFIG-SPELLCHECKCOMPONENT.XML, SOLRCONFIG-PHRASESUGGEST.XML, SCHEMA-DFR.XML, BAD-SCHEMA-CURRENCY-MULTIVALUED.XML, BAD-SCHEMA-NOT-INDEXED-BUT-POS.XML, KEEP-1.TXT, OPEN-EXCHANGE-RATES.JSON, SCHEMA-SPATIAL.XML, STOPWITHBOM.TXT, SOLRCONFIG-POSTINGSHIGHLIGHT.XML, SCHEMA-BINARYFIELD.XML, SOLRCONFIG-SPELLCHECKER.XML, SOLRCONFIG-UPDATE-PROCESSOR-CHAINS.XML, BAD-SCHEMA-OMIT-TF-BUT-NOT-POS.XML, SCHEMA-XINCLUDE.XML, BAD-SCHEMA-DUP-FIELDTYPE.XML, SOLRCONFIG-MASTER1.XML, SCHEMA-BEHAVIOR.XML, SYNONYMS.TXT, SOLRCONFIG-MINIMAL.XML, SCHEMA-DOCVALUESMULTI.XML, BAD-SCHEMA-UNSUPPORTED-DOCVALUES.XML, BAD-SCHEMA-CURRENCY-DYNAMIC-MULTIVALUED.XML, SCHEMA_CODEC.XML, BAD-SCHEMA-SWEETSPOT-PARTIAL-HYPERBOLIC.XML, SOLRCONFIG-SOLR-749.XML, SOLRCONFIG-MASTER1-KEEPONEBACKUP.XML, SCHEMA-EFF.XML, STOP-2.TXT, SOLRCONFIG-FUNCTIONQUERY.XML, SCHEMA-LMDIRICHLET.XML, SOLRCONFIG-TERMINDEX.XML, SOLRCONFIG-ELEVATE.XML, BAD-SCHEMA-SWEETSPOT-PARTIAL-NORMS.XML, BAD-SCHEMA-SWEETSPOT-PARTIAL-BASELINE.XML, STOPWORDS.TXT, SCHEMA-FOLDING.XML, SCHEMA-STOP-KEEP.XML, FUZZYSUGGEST.TXT, BAD-SCHEMA-NOT-INDEXED-BUT-NORMS.XML, SCHEMA-REST.XML, SOLRCONFIG-SOLCOREPROPERTIES.XML, STOP-1.TXT, SOLRCONFIG-MASTER2.XML, SCHEMA-SPELLCHECKER.XML, SOLRCONFIG-RESPONSE-LOG-COMPONENT.XML, SOLRCONFIG-LAZYWRITER.XML, SCHEMA-LUCENEMATCHVERSION.XML, BAD-MP-SOLRCONFIG.XML, FRENCHARTICLES.TXT, SCHEMA15.XML, SOLRCONFIG-REQHANDLER.INCL, SCHEMASURROUND.XML, SCHEMA-COLLATEFILTER.XML, SOLRCONFIG-MASTER3.XML, HUNSPELL-TEST.DIC, SOLRCONFIG-XINCLUDE.XML, BAD-SCHEMA-CODEC-GLOBAL-VS-FT-MISMATCH.XML, SOLRCONFIG-SLAVE1.XML, SOLRCONFIG-DELPOLICY1.XML, SCHEMA-SIM.XML, SCHEMA-SNIPPET-FIELD.XML, SCHEMA-COLLATE.XML, STOP-SNOWBALL.TXT, BAD-SCHEMA-SIM-GLOBAL-VS-FT-MISMATCH.XML, PROTWORDS.TXT, SCHEMA-TRIE.XML, SOLRCONFIG_CODEC.XML, SCHEMA-SYNONYM-TOKENIZER.XML, BAD-SOLRCONFIG-INVALID-SCRIPTFILE.XML, JASUGGEST.TXT, SCHEMA-DOCVALUESFACETING.XML, SCHEMA-TFIDF.XML, SOLRCONFIG-SCRIPT-UPDATEPROCESSOR.XML, SCHEMA-LMJELINEKMERCER.XML, PHRASESUGGEST.TXT, BAD-SOLRCONFIG-MISSING-SCRIPTFILE.XML, SOLRCONFIG-BASIC-LUCENEVERSION31.XML, BAD-SCHEMA-UNIQUEKEY-USES-DEFAULT.XML, OLD_SYNONYMS.TXT, SOLRCONFIG-DELPOLICY2.XML, SOLRCONFIG-NATIVELOCK.XML, XSLT, BAD-SCHEMA-DUP-FIELD.XML, SOLRCONFIG-NOCACHE.XML, SCHEMA-BM25.XML, BAD-SCHEMA-SWEETSPOT-BOTH-TF.XML, ADDFIELDS.UPDATEPROCESSOR.JS, SOLRCONFIG-ALTDIRECTORY.XML, SOLRCONFIG-QUERYSENDER-NOQUERY.XML, COMPOUNDDICTIONARY.TXT, SOLRCONFIG-INDEXCONFIG.XML, SOLRCONFIG_PERF.XML, BAD-CURRENCY.XML, BAD-SCHEMA-CURRENCY-FT-BOGUS-DEFAULT-CODE.XML, BAD-SCHEMA-ANALYZER-CLASS-AND-NESTED.XML, SCHEMA-NOT-REQUIRED-UNIQUE-KEY.XML, KEEP-2.TXT, SCHEMA12.XML, BAD-SCHEMA-UNIQUEKEY-IS-COPYFIELD-DEST.XML, MAPPING-ISOLATIN1ACCENT.TXT, BAD_SOLRCONFIG.XML, BAD-SCHEMA-EXTERNAL-FILEFIELD.XML]
[junit4:junit4]   2> 4752 T113 oass.SolrIndexSearcher.<init> Opening Searcher@74646217 main
[junit4:junit4]   2> 4752 T113 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 4753 T113 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 4753 T113 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 4756 T113 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 4771 T118 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@74646217 main{StandardDirectoryReader(segments_3:7:nrt _1(4.3):C1)}
[junit4:junit4]   2> 4779 T113 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 4779 T113 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 4779 T113 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4:junit4]   2> 4787 T113 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/index3941139413tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@2d7f6d79)),segFN=segments_3,generation=3,filenames=[_1.doc, _1.nvm, _1.fdx, _1.pos, _1.fdt, _1.si, _1.nvd, _1.fnm, _1.tip, _1.tim, segments_3]
[junit4:junit4]   2> 4787 T113 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[_1.doc, _1.nvm, _1.fdx, _1.pos, _1.fdt, _1.si, _1.nvd, _1.fnm, _1.tip, _1.tim, segments_3]
[junit4:junit4]   2> 4787 T113 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 4790 T113 oass.SolrIndexSearcher.<init> Opening Searcher@712f15db main
[junit4:junit4]   2> 4791 T113 oasc.CoreContainer.registerCore replacing core: collection1
[junit4:junit4]   2> 4791 T113 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@3d8fe9b5
[junit4:junit4]   2> 4792 T118 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@712f15db main{StandardDirectoryReader(segments_3:7:nrt _1(4.3):C1)}
[junit4:junit4]   2> 4798 T113 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=4,autocommit maxTime=1200ms,autocommits=1,soft autocommit maxTime=500ms,soft autocommits=2,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=2,cumulative_deletesById=1,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 4799 T113 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> ASYNC  NEW_CORE C5 name=collection1 org.apache.solr.core.SolrCore@1a71fa61
[junit4:junit4]   2> 4811 T113 C5 UPDATE [collection1] webapp=null path=null params={} {add=[529]} 0 4
[junit4:junit4]   2> 5312 T120 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4:junit4]   2> 5330 T120 oass.SolrIndexSearcher.<init> Opening Searcher@512dcf64 main
[junit4:junit4]   2> 5331 T120 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 5333 T118 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@512dcf64 main{StandardDirectoryReader(segments_3:9:nrt _1(4.3):C1 _2(4.3):C1)}
[junit4:junit4]   2> 5344 T113 C5 UPDATE [collection1] webapp=null path=null params={} {add=[530]} 0 4
[junit4:junit4]   2> 5845 T120 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4:junit4]   2> 5858 T120 oass.SolrIndexSearcher.<init> Opening Searcher@2c957974 main
[junit4:junit4]   2> 5858 T120 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 5861 T118 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2c957974 main{StandardDirectoryReader(segments_3:11:nrt _1(4.3):C1 _2(4.3):C1 _3(4.3):C1)}
[junit4:junit4]   2> 6012 T119 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 6111 T119 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/index3941139413tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@2d7f6d79)),segFN=segments_3,generation=3,filenames=[_1.doc, _1.nvm, _1.fdx, _1.pos, _1.fdt, _1.si, _1.nvd, _1.fnm, _1.tip, _1.tim, segments_3]
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/index3941139413tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@2d7f6d79)),segFN=segments_4,generation=4,filenames=[_2.pos, _1.doc, _2.si, _3.tim, _3.fdt, _3.pos, _3.fnm, _1.fnm, _2.doc, _2.tim, _3.nvd, _1.pos, _3.nvm, _1.tip, _1.tim, _1.nvm, _1.nvd, _3.doc, _2.fdt, _2.fdx, _2.fnm, _3.fdx, _1.fdx, _2.tip, _2.nvm, _1.fdt, _1.si, _2.nvd, _3.si, _3.tip, segments_4]
[junit4:junit4]   2> 6111 T119 oasc.SolrDeletionPolicy.updateCommits newest commit = 4[_2.pos, _1.doc, _2.si, _3.tim, _3.fdt, _3.pos, _3.fnm, _1.fnm, _2.doc, _2.tim, _3.nvd, _1.pos, _3.nvm, _1.tip, _1.tim, _1.nvm, _1.nvd, _3.doc, _2.fdt, _2.fdx, _2.fnm, _3.fdx, _1.fdx, _2.tip, _2.nvm, _1.fdt, _1.si, _2.nvd, _3.si, _3.tip, segments_4]
[junit4:junit4]   2> 6112 T119 oass.SolrIndexSearcher.<init> Opening Searcher@389bc998 main
[junit4:junit4]   2> 6112 T119 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4]   2> 6114 T118 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@389bc998 main{StandardDirectoryReader(segments_3:11:nrt _1(4.3):C1 _2(4.3):C1 _3(4.3):C1)}
[junit4:junit4]   2> 9314 T113 oas.SolrTestCaseJ4.tearDown ###Ending testSoftAndHardCommitMaxTimeMixedAdds
[junit4:junit4]   2> 9322 T113 oas.SolrTestCaseJ4.setUp ###Starting testSoftAndHardCommitMaxTimeRapidAdds
[junit4:junit4]   2> 9322 T113 oasc.CoreContainer.reload Reloading SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4]   2> 9323 T113 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4]   2> 9325 T113 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4]   2> 9326 T113 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 9418 T113 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_43
[junit4:junit4]   2> 9514 T113 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 9515 T113 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 9525 T113 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 10174 T113 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 10187 T113 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 10192 T113 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 10211 T113 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 10217 T113 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 10222 T113 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 10223 T113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 10224 T113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 10224 T113 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 10225 T113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 10226 T113 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 10226 T113 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-files/solr/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./solrtest-SoftAutoCommitTest-1363915571369/
[junit4:junit4]   2> 10227 T113 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@2299e3c9
[junit4:junit4]   2> 10228 T113 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./solrtest-SoftAutoCommitTest-1363915571369/index/
[junit4:junit4]   2> 10228 T113 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4]   2> 10231 T113 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 10232 T113 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4]   2> 10232 T113 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 10233 T113 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4]   2> 10234 T113 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 10234 T113 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 10235 T113 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 10236 T113 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 10237 T113 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 10238 T113 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4]   2> 10239 T113 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4]   2> 10240 T113 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 10240 T113 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4]   2> 10241 T113 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4]   2> 10242 T113 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4]   2> 10243 T113 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 10244 T113 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10245 T113 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10245 T113 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10246 T113 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10247 T113 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10248 T113 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10249 T113 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10250 T113 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4]   2> 10251 T113 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4]   2> 10252 T113 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4]   2> 10264 T113 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 10268 T113 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4]   2> 10271 T113 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [THROW.ERROR.ON.ADD.UPDATEPROCESSOR.JS, SOLRCONFIG-HIGHLIGHT.XML, SCHEMA-REQUIRED-FIELDS.XML, BAD-SCHEMA-DOCVALUES-NOT-REQUIRED-NO-DEFAULT.XML, SCHEMA-MINIMAL.XML, BAD-SCHEMA-DUP-DYNAMICFIELD.XML, SCHEMA-REPLICATION2.XML, TRIVIAL.UPDATEPROCESSOR1.JS, SOLRCONFIG-CACHING.XML, SCHEMA-POSTINGSHIGHLIGHT.XML, REGEX-BOOST-PROCESSOR-TEST.TXT, SOLRCONFIG-REPEATER.XML, BAD-SCHEMA-CURRENCY-FT-BOGUS-CODE-IN-XML.XML, BAD-SCHEMA-NONTEXT-ANALYZER.XML, CURRENCY.XML, SOLRCONFIG-MERGEPOLICY.XML, SOLRCONFIG-TLOG.XML, SOLRCONFIG-MASTER.XML, SOLRCONFIG-COMPONENTS-NAME.XML, BAD-SCHEMA-UNIQUEKEY-MULTIVALUED.XML, SCHEMA11.XML, SOLRCONFIG-BASIC.XML, DA_COMPOUNDDICTIONARY.TXT, MISSLEADING.EXTENSION.UPDATEPROCESSOR.JS.TXT, SCHEMA-COPYFIELD-TEST.XML, SOLRCONFIG-SLAVE.XML, ELEVATE.XML, SOLRCONFIG-PROPINJECT-INDEXDEFAULT.XML, TRIVIAL.UPDATEPROCESSOR0.JS, SCHEMA-SWEETSPOT.XML, BAD-SOLRCONFIG-BOGUS-SCRIPTENGINE-NAME.XML, SCHEMA-CHARFILTERS.XML, SCHEMA-IB.XML, SOLRCONFIG-QUERYSENDER.XML, SOLRCONFIG-SNIPPET-PROCESSOR.XML, SCHEMA-REPLICATION1.XML, DA_UTF8.XML, SCHEMA-TINY.XML, CONDITIONAL.UPDATEPROCESSOR.JS, MISSING.FUNCTIONS.UPDATEPROCESSOR.JS, HYPHENATION.DTD, SOLRCONFIG-ENABLEPLUGIN.XML, STEMDICT.TXT, SCHEMA-PHRASESUGGEST.XML, HUNSPELL-TEST.AFF, BAD-SCHEMA-CURRENCY-FT-OER-NORATES.XML, SCHEMA-SNIPPET-TYPE.XML, STOPTYPES-1.TXT, STOPWORDSWRONGENCODING.TXT, SCHEMA-NUMERIC.XML, SOLRCONFIG-TRANSFORMERS.XML, SOLRCONFIG-PROPINJECT.XML, BAD-SCHEMA-NOT-INDEXED-BUT-TF.XML, SOLRCONFIG-SIMPLELOCK.XML, SCHEMA-DOCVALUES.XML, WDFTYPES.TXT, STOPTYPES-2.TXT, SCHEMA-REVERSED.XML, BAD-SCHEMA-CURRENCY-FT-MULTIVALUED.XML, SOLRCONFIG-SPELLCHECKCOMPONENT.XML, SOLRCONFIG-PHRASESUGGEST.XML, SCHEMA-DFR.XML, BAD-SCHEMA-CURRENCY-MULTIVALUED.XML, BAD-SCHEMA-NOT-INDEXED-BUT-POS.XML, KEEP-1.TXT, OPEN-EXCHANGE-RATES.JSON, SCHEMA-SPATIAL.XML, STOPWITHBOM.TXT, SOLRCONFIG-POSTINGSHIGHLIGHT.XML, SCHEMA-BINARYFIELD.XML, SOLRCONFIG-SPELLCHECKER.XML, SOLRCONFIG-UPDATE-PROCESSOR-CHAINS.XML, BAD-SCHEMA-OMIT-TF-BUT-NOT-POS.XML, SCHEMA-XINCLUDE.XML, BAD-SCHEMA-DUP-FIELDTYPE.XML, SOLRCONFIG-MASTER1.XML, SCHEMA-BEHAVIOR.XML, SYNONYMS.TXT, SOLRCONFIG-MINIMAL.XML, SCHEMA-DOCVALUESMULTI.XML, BAD-SCHEMA-UNSUPPORTED-DOCVALUES.XML, BAD-SCHEMA-CURRENCY-DYNAMIC-MULTIVALUED.XML, SCHEMA_CODEC.XML, BAD-SCHEMA-SWEETSPOT-PARTIAL-HYPERBOLIC.XML, SOLRCONFIG-SOLR-749.XML, SOLRCONFIG-MASTER1-KEEPONEBACKUP.XML, SCHEMA-EFF.XML, STOP-2.TXT, SOLRCONFIG-FUNCTIONQUERY.XML, SCHEMA-LMDIRICHLET.XML, SOLRCONFIG-TERMINDEX.XML, SOLRCONFIG-ELEVATE.XML, BAD-SCHEMA-SWEETSPOT-PARTIAL-NORMS.XML, BAD-SCHEMA-SWEETSPOT-PARTIAL-BASELINE.XML, STOPWORDS.TXT, SCHEMA-FOLDING.XML, SCHEMA-STOP-KEEP.XML, FUZZYSUGGEST.TXT, BAD-SCHEMA-NOT-INDEXED-BUT-NORMS.XML, SCHEMA-REST.XML, SOLRCONFIG-SOLCOREPROPERTIES.XML, STOP-1.TXT, SOLRCONFIG-MASTER2.XML, SCHEMA-SPELLCHECKER.XML, SOLRCONFIG-RESPONSE-LOG-COMPONENT.XML, SOLRCONFIG-LAZYWRITER.XML, SCHEMA-LUCENEMATCHVERSION.XML, BAD-MP-SOLRCONFIG.XML, FRENCHARTICLES.TXT, SCHEMA15.XML, SOLRCONFIG-REQHANDLER.INCL, SCHEMASURROUND.XML, SCHEMA-COLLATEFILTER.XML, SOLRCONFIG-MASTER3.XML, HUNSPELL-TEST.DIC, SOLRCONFIG-XINCLUDE.XML, BAD-SCHEMA-CODEC-GLOBAL-VS-FT-MISMATCH.XML, SOLRCONFIG-SLAVE1.XML, SOLRCONFIG-DELPOLICY1.XML, SCHEMA-SIM.XML, SCHEMA-SNIPPET-FIELD.XML, SCHEMA-COLLATE.XML, STOP-SNOWBALL.TXT, BAD-SCHEMA-SIM-GLOBAL-VS-FT-MISMATCH.XML, PROTWORDS.TXT, SCHEMA-TRIE.XML, SOLRCONFIG_CODEC.XML, SCHEMA-SYNONYM-TOKENIZER.XML, BAD-SOLRCONFIG-INVALID-SCRIPTFILE.XML, JASUGGEST.TXT, SCHEMA-DOCVALUESFACETING.XML, SCHEMA-TFIDF.XML, SOLRCONFIG-SCRIPT-UPDATEPROCESSOR.XML, SCHEMA-LMJELINEKMERCER.XML, PHRASESUGGEST.TXT, BAD-SOLRCONFIG-MISSING-SCRIPTFILE.XML, SOLRCONFIG-BASIC-LUCENEVERSION31.XML, BAD-SCHEMA-UNIQUEKEY-USES-DEFAULT.XML, OLD_SYNONYMS.TXT, SOLRCONFIG-DELPOLICY2.XML, SOLRCONFIG-NATIVELOCK.XML, XSLT, BAD-SCHEMA-DUP-FIELD.XML, SOLRCONFIG-NOCACHE.XML, SCHEMA-BM25.XML, BAD-SCHEMA-SWEETSPOT-BOTH-TF.XML, ADDFIELDS.UPDATEPROCESSOR.JS, SOLRCONFIG-ALTDIRECTORY.XML, SOLRCONFIG-QUERYSENDER-NOQUERY.XML, COMPOUNDDICTIONARY.TXT, SOLRCONFIG-INDEXCONFIG.XML, SOLRCONFIG_PERF.XML, BAD-CURRENCY.XML, BAD-SCHEMA-CURRENCY-FT-BOGUS-DEFAULT-CODE.XML, BAD-SCHEMA-ANALYZER-CLASS-AND-NESTED.XML, SCHEMA-NOT-REQUIRED-UNIQUE-KEY.XML, KEEP-2.TXT, SCHEMA12.XML, BAD-SCHEMA-UNIQUEKEY-IS-COPYFIELD-DEST.XML, MAPPING-ISOLATIN1ACCENT.TXT, BAD_SOLRCONFIG.XML, BAD-SCHEMA-EXTERNAL-FILEFIELD.XML]
[junit4:junit4]   2> 10274 T113 oass.SolrIndexSearcher.<init> Opening Searcher@710afce3 main
[junit4:junit4]   2> 10275 T113 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 10276 T113 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 10277 T113 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4]   2> 10280 T113 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4]   2> 10299 T121 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@710afce3 main{StandardDirectoryReader(segments_4:11:nrt _1(4.3):C1 _2(4.3):C1 _3(4.3):C1)}
[junit4:junit4]   2> 10310 T113 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4]   2> 10310 T113 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4]   2> 10311 T113 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4:junit4]   2> 10328 T113 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/index3941139413tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@2d7f6d79)),segFN=segments_4,generation=4,filenames=[_2.si, _1.doc, _2.pos, _3.tim, _3.fnm, _3.pos, _3.fdt, _1.fnm, _2.doc, _2.tim, _3.nvd, _1.pos, _3.nvm, _1.tip, _1.tim, _1.nvm, _1.nvd, _3.doc, _2.fdt, _2.fdx, _2.fnm, _3.fdx, _1.fdx, _2.tip, _2.nvm, _1.fdt, _1.si, _2.nvd, _3.tip, _3.si, segments_4]
[junit4:junit4]   2> 10329 T113 oasc.SolrDeletionPolicy.updateCommits newest commit = 4[_2.si, _1.doc, _2.pos, _3.tim, _3.fnm, _3.pos, _3.fdt, _1.fnm, _2.doc, _2.tim, _3.nvd, _1.pos, _3.nvm, _1.tip, _1.tim, _1.nvm, _1.nvd, _3.doc, _2.fdt, _2.fdx, _2.fnm, _3.fdx, _1.fdx, _2.tip, _2.nvm, _1.fdt, _1.si, _2.nvd, _3.tip, _3.si, segments_4]
[junit4:junit4]   2> 10330 T113 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4]   2> 10341 T113 oass.SolrIndexSearcher.<init> Opening Searcher@54fabfeb main
[junit4:junit4]   2> 10342 T113 oasc.CoreContainer.registerCore replacing core: collection1
[junit4:junit4]   2> 10342 T113 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@1a71fa61
[junit4:junit4]   2> 10344 T121 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@54fabfeb main{StandardDirectoryReader(segments_4:11:nrt _1(4.3):C1 _2(4.3):C1 _3(4.3):C1)}
[junit4:junit4]   2> 10352 T113 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=3,autocommit maxTime=1200ms,autocommits=1,soft autocommit maxTime=500ms,soft autocommits=2,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=2,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 10353 T113 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> ASYNC  NEW_CORE C6 name=collection1 org.apache.solr.core.SolrCore@3a2634af
[junit4:junit4]   2> 10368 T113 C6 UPDATE [collection1] webapp=null path=null params={} {add=[5000]} 0 4
[junit4:junit4]   2> 10380 T113 C6 UPDATE [collection1] webapp=null path=null params={} {add=[5001]} 0 2
[junit4:junit4]   2> 10461 T113 C6 UPDATE [collection1] webapp=null path=null params={} {add=[5002]} 0 2
[junit4:junit4]   2> 10473 T113 C6 UPDATE [collection1] webapp=null path=null params={} {add=[5003]} 0 2
[junit4:junit4]   2> 10484 T113 C6 UPDATE [collection1] webapp=null path=null params={} {add=[5004]} 0 2
[junit4:junit4]   2> 10487 T113 oas.SolrTestCaseJ4.tearDown ###Ending testSoftAndHardCommitMaxTimeRapidAdds
[junit4:junit4]   2> 10490 T113 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4]   2> 10490 T113 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1085112373
[junit4:junit4]   2> 10491 T113 oasc.SolrCore.close [collection1]  CLOSING SolrCore org.apache.solr.core.SolrCore@3a2634af
[junit4:junit4]   2> 10508 T113 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=0,autocommit maxTime=1200ms,autocommits=0,soft autocommit maxTime=500ms,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=5,adds=5,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=5,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0}
[junit4:junit4]   2> 10509 T113 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4]   2> 10510 T113 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4]   2> 10510 T113 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4]   2> 10576 T113 C6 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/index3941139413tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@2d7f6d79)),segFN=segments_4,generation=4,filenames=[_2.si, _1.doc, _2.pos, _3.tim, _3.fnm, _3.pos, _3.fdt, _1.fnm, _2.doc, _2.tim, _3.nvd, _1.pos, _3.nvm, _1.tip, _1.tim, _1.nvm, _1.nvd, _3.doc, _2.fdt, _2.fdx, _2.fnm, _3.fdx, _1.fdx, _2.tip, _2.nvm, _1.fdt, _1.si, _2.nvd, _3.tip, _3.si, segments_4]
[junit4:junit4]   2> 		commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/index3941139413tmp lockFactory=org.apache.lucene.store.NativeFSLockFactory@2d7f6d79)),segFN=segments_5,generation=5,filenames=[_2.si, _1.doc, _2.pos, _3.tim, _4.fnm, _3.fnm, _3.pos, _3.fdt, _1.fnm, _2.doc, _2.tim, _4.fdx, _4.doc, _3.nvd, _1.pos, _4.tip, _3.nvm, _1.tip, _1.tim, _1.nvm, _4.tim, _4.pos, _1.nvd, _3.doc, _2.fdt, _4.si, _4.fdt, _2.fdx, _2.fnm, _3.fdx, _1.fdx, _2.tip, _4.nvd, _2.nvm, _1.fdt, _1.si, _2.nvd, _3.tip, _3.si, segments_5, _4.nvm]
[junit4:junit4]   2> 10577 T113 C6 oasc.SolrDeletionPolicy.updateCommits newest commit = 5[_2.si, _1.doc, _2.pos, _3.tim, _4.fnm, _3.fnm, _3.pos, _3.fdt, _1.fnm, _2.doc, _2.tim, _4.fdx, _4.doc, _3.nvd, _1.pos, _4.tip, _3.nvm, _1.tip, _1.tim, _1.nvm, _4.tim, _4.pos, _1.nvd, _3.doc, _2.fdt, _4.si, _4.fdt, _2.fdx, _2.fnm, _3.fdx, _1.fdx, _2.tip, _4.nvd, _2.nvm, _1.fdt, _1.si, _2.nvd, _3.tip, _3.si, segments_5, _4.nvm]
[junit4:junit4]   2> 10581 T113 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4]   2> 10583 T113 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./solrtest-SoftAutoCommitTest-1363915571369
[junit4:junit4]   2> 10583 T113 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./solrtest-SoftAutoCommitTest-1363915571369
[junit4:junit4]   2> 10584 T113 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./solrtest-SoftAutoCommitTest-1363915571369/index
[junit4:junit4]   2> 10585 T113 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J0/./solrtest-SoftAutoCommitTest-1363915571369/index
[junit4:junit4]   2> NOTE: test params are: codec=Asserting, sim=RandomSimilarityProvider(queryNorm=true,coord=yes): {}, locale=pt_BR, timezone=Antarctica/Syowa
[junit4:junit4]   2> NOTE: FreeBSD 9.0-RELEASE amd64/Oracle Corporation 1.7.0_17 (64-bit)/cpus=16,threads=1,free=124845480,total=159383552
[junit4:junit4]   2> NOTE: All tests run in this JVM: [SpellCheckCollatorTest, SolrCoreTest, TestSort, TestLazyCores, TestBinaryField, SoftAutoCommitTest]
[junit4:junit4] Completed on J0 in 10.64s, 3 tests, 1 failure <<< FAILURES!

[...truncated 247 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.SyncSliceTest
[junit4:junit4]   2> 0 T881 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4]   2> 5 T881 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4]   2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./solrtest-SyncSliceTest-1363915773517
[junit4:junit4]   2> 6 T881 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4]   2> 6 T882 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4]   2> 9 T882 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4]   2> 9 T882 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4]   2> 9 T882 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4]   2> 10 T882 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> 11 T882 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-1363915773517/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4]   2> 107 T881 oasc.ZkTestServer.run start zk server on port:29270
[junit4:junit4]   2> 107 T881 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:29270 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@235013dc
[junit4:junit4]   2> 108 T881 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 109 T887 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:29270. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 109 T887 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:29270, initiating session
[junit4:junit4]   2> 110 T883 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:29271
[junit4:junit4]   2> 110 T883 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:29271
[junit4:junit4]   2> 110 T885 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4]   2> 114 T885 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8fb716530000 with negotiated timeout 10000 for client /140.211.11.196:29271
[junit4:junit4]   2> 114 T887 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:29270, sessionid = 0x13d8fb716530000, negotiated timeout = 10000
[junit4:junit4]   2> 115 T888 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@235013dc name:ZooKeeperConnection Watcher:127.0.0.1:29270 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 115 T881 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 115 T881 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4]   2> 118 T886 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8fb716530000
[junit4:junit4]   2> 129 T888 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 130 T883 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:29271 which had sessionid 0x13d8fb716530000
[junit4:junit4]   2> 129 T881 oaz.ZooKeeper.close Session: 0x13d8fb716530000 closed
[junit4:junit4]   2> 130 T881 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:29270/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@198a7a13
[junit4:junit4]   2> 131 T881 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 131 T889 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:29270. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 132 T889 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:29270, initiating session
[junit4:junit4]   2> 132 T883 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:29272
[junit4:junit4]   2> 132 T883 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:29272
[junit4:junit4]   2> 134 T885 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8fb716530001 with negotiated timeout 10000 for client /140.211.11.196:29272
[junit4:junit4]   2> 134 T889 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:29270, sessionid = 0x13d8fb716530001, negotiated timeout = 10000
[junit4:junit4]   2> 134 T890 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@198a7a13 name:ZooKeeperConnection Watcher:127.0.0.1:29270/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 134 T881 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 135 T881 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4]   2> 145 T881 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4]   2> 149 T881 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4]   2> 151 T881 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4]   2> 160 T881 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> 161 T881 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4]   2> 174 T881 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/schema.xml to /configs/conf1/schema.xml
[junit4:junit4]   2> 175 T881 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4]   2> 280 T881 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> 281 T881 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4]   2> 284 T881 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> 285 T881 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4]   2> 294 T881 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> 295 T881 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4]   2> 298 T881 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> 299 T881 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4]   2> 302 T881 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> 303 T881 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4]   2> 306 T881 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> 307 T881 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4]   2> 310 T881 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> 311 T881 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4]   2> 314 T886 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8fb716530001
[junit4:junit4]   2> 321 T890 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 321 T883 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:29272 which had sessionid 0x13d8fb716530001
[junit4:junit4]   2> 321 T881 oaz.ZooKeeper.close Session: 0x13d8fb716530001 closed
[junit4:junit4]   2> 469 T881 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 475 T881 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:29273
[junit4:junit4]   2> 476 T881 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 476 T881 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 477 T881 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-controljetty-1363915773833
[junit4:junit4]   2> 477 T881 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-controljetty-1363915773833/solr.xml
[junit4:junit4]   2> 477 T881 oasc.CoreContainer.<init> New CoreContainer 1378369635
[junit4:junit4]   2> 478 T881 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-controljetty-1363915773833/'
[junit4:junit4]   2> 478 T881 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-controljetty-1363915773833/'
[junit4:junit4]   2> 526 T881 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 527 T881 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 527 T881 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 527 T881 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 528 T881 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 528 T881 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 528 T881 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 529 T881 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 529 T881 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 529 T881 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 547 T881 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 562 T881 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:29270/solr
[junit4:junit4]   2> 562 T881 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 563 T881 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:29270 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@50782f92
[junit4:junit4]   2> 564 T881 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 564 T900 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:29270. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 565 T900 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:29270, initiating session
[junit4:junit4]   2> 565 T883 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:29274
[junit4:junit4]   2> 566 T883 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:29274
[junit4:junit4]   2> 568 T885 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8fb716530002 with negotiated timeout 20000 for client /140.211.11.196:29274
[junit4:junit4]   2> 568 T900 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:29270, sessionid = 0x13d8fb716530002, negotiated timeout = 20000
[junit4:junit4]   2> 568 T901 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@50782f92 name:ZooKeeperConnection Watcher:127.0.0.1:29270 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 569 T881 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 570 T886 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8fb716530002
[junit4:junit4]   2> 616 T901 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 617 T883 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:29274 which had sessionid 0x13d8fb716530002
[junit4:junit4]   2> 616 T881 oaz.ZooKeeper.close Session: 0x13d8fb716530002 closed
[junit4:junit4]   2> 617 T881 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 626 T881 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:29270/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@4b03257c
[junit4:junit4]   2> 627 T881 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 628 T902 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:29270. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 628 T902 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:29270, initiating session
[junit4:junit4]   2> 628 T883 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:29275
[junit4:junit4]   2> 628 T883 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:29275
[junit4:junit4]   2> 631 T885 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8fb716530003 with negotiated timeout 20000 for client /140.211.11.196:29275
[junit4:junit4]   2> 631 T902 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:29270, sessionid = 0x13d8fb716530003, negotiated timeout = 20000
[junit4:junit4]   2> 631 T903 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4b03257c name:ZooKeeperConnection Watcher:127.0.0.1:29270/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 631 T881 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 633 T881 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4]   2> 636 T886 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8fb716530003 type:create cxid:0x7 zxid:0x1b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 638 T881 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4]   2> 641 T881 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4]   2> 644 T881 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:29273_
[junit4:junit4]   2> 644 T886 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8fb716530003 type:delete cxid:0x12 zxid:0x1e txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:29273_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:29273_
[junit4:junit4]   2> 653 T881 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:29273_
[junit4:junit4]   2> 657 T881 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4]   2> 675 T886 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8fb716530003 type:delete cxid:0x20 zxid:0x23 txntype:-1 reqpath:n/a Error Path:/solr/overseer_elect/leader Error:KeeperErrorCode = NoNode for /solr/overseer_elect/leader
[junit4:junit4]   2> 688 T881 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4]   2> 691 T881 oasc.Overseer.start Overseer (id=89385584133603331-127.0.0.1:29273_-n_0000000000) starting
[junit4:junit4]   2> 691 T886 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8fb716530003 type:create cxid:0x25 zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 694 T886 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8fb716530003 type:create cxid:0x26 zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 696 T886 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8fb716530003 type:create cxid:0x28 zxid:0x27 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 697 T881 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4]   2> 716 T886 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8fb716530003 type:create cxid:0x2e zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 720 T905 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4]   2> 721 T881 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4]   2> 727 T881 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4]   2> 729 T881 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 731 T904 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4]   2> 735 T906 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-controljetty-1363915773833/collection1
[junit4:junit4]   2> 735 T906 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4]   2> 736 T906 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 736 T906 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4]   2> 738 T906 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-controljetty-1363915773833/collection1/'
[junit4:junit4]   2> 739 T906 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-controljetty-1363915773833/collection1/lib/README' to classloader
[junit4:junit4]   2> 739 T906 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-controljetty-1363915773833/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 787 T906 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_43
[junit4:junit4]   2> 848 T906 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 949 T906 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 957 T906 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 1590 T906 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 1603 T906 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 1607 T906 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 1625 T906 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1630 T906 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 1635 T906 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1636 T906 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 1637 T906 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 1638 T906 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 1639 T906 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 1639 T906 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 1640 T906 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 1676 T906 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-controljetty-1363915773833/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1363915773517/control/data/
[junit4:junit4]   2> 1676 T906 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@bb933cb
[junit4:junit4]   2> 1677 T906 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 1678 T906 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1363915773517/control/data
[junit4:junit4]   2> 1678 T906 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1363915773517/control/data/index/
[junit4:junit4]   2> 1679 T906 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1363915773517/control/data/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 1680 T906 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1363915773517/control/data/index
[junit4:junit4]   2> 1687 T906 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1363915773517/control/data/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@2b298bd5; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 1687 T906 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 1690 T906 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 1690 T906 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 1691 T906 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 1692 T906 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 1692 T906 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 1692 T906 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 1693 T906 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 1693 T906 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 1693 T906 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 1707 T906 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 1715 T906 oass.SolrIndexSearcher.<init> Opening Searcher@4d28aa6a main
[junit4:junit4]   2> 1716 T906 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 1716 T906 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 1720 T907 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4d28aa6a main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 1722 T906 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 1722 T906 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 2236 T904 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 2237 T904 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> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:29273_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:29273"}
[junit4:junit4]   2> 2237 T904 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4]   2> 2238 T904 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 2290 T903 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> 2725 T906 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 2725 T906 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:29273 collection:control_collection shard:shard1
[junit4:junit4]   2> 2726 T906 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4]   2> 2764 T886 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8fb716530003 type:delete cxid:0x82 zxid:0x35 txntype:-1 reqpath:n/a Error Path:/solr/collections/control_collection/leaders Error:KeeperErrorCode = NoNode for /solr/collections/control_collection/leaders
[junit4:junit4]   2> 2765 T906 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 2765 T886 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8fb716530003 type:create cxid:0x83 zxid:0x36 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 2768 T906 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 2768 T906 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 2769 T906 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:29273/collection1/
[junit4:junit4]   2> 2769 T906 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 2770 T906 oasc.SyncStrategy.syncToMe http://127.0.0.1:29273/collection1/ has no replicas
[junit4:junit4]   2> 2770 T906 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:29273/collection1/
[junit4:junit4]   2> 2770 T906 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4]   2> 2775 T886 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8fb716530003 type:create cxid:0x8e zxid:0x3a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 3795 T904 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3839 T903 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> 3899 T906 oasc.ZkController.register We are http://127.0.0.1:29273/collection1/ and leader is http://127.0.0.1:29273/collection1/
[junit4:junit4]   2> 3899 T906 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:29273
[junit4:junit4]   2> 3899 T906 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 3900 T906 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 3900 T906 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 3902 T906 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 3903 T881 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1
[junit4:junit4]   2> 3904 T881 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 3905 T881 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 3921 T881 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4]   2> 3927 T881 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:29270/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@771203c2
[junit4:junit4]   2> 3928 T881 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 3929 T909 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:29270. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 3929 T909 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:29270, initiating session
[junit4:junit4]   2> 3930 T883 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:29280
[junit4:junit4]   2> 3930 T883 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:29280
[junit4:junit4]   2> 3931 T885 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8fb716530004 with negotiated timeout 10000 for client /140.211.11.196:29280
[junit4:junit4]   2> 3931 T909 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:29270, sessionid = 0x13d8fb716530004, negotiated timeout = 10000
[junit4:junit4]   2> 3932 T910 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@771203c2 name:ZooKeeperConnection Watcher:127.0.0.1:29270/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 3932 T881 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 3933 T881 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 3939 T881 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4]   2> 4149 T881 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 4153 T881 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:29281
[junit4:junit4]   2> 4153 T881 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 4154 T881 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 4154 T881 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty1-1363915777452
[junit4:junit4]   2> 4155 T881 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty1-1363915777452/solr.xml
[junit4:junit4]   2> 4155 T881 oasc.CoreContainer.<init> New CoreContainer 917966469
[junit4:junit4]   2> 4156 T881 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty1-1363915777452/'
[junit4:junit4]   2> 4157 T881 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty1-1363915777452/'
[junit4:junit4]   2> 4220 T881 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 4221 T881 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 4221 T881 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 4222 T881 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 4222 T881 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 4223 T881 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 4223 T881 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 4224 T881 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 4224 T881 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 4224 T881 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 4246 T881 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 4266 T881 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:29270/solr
[junit4:junit4]   2> 4266 T881 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 4267 T881 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:29270 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@58d62cd8
[junit4:junit4]   2> 4268 T881 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4268 T920 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:29270. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 4269 T920 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:29270, initiating session
[junit4:junit4]   2> 4270 T883 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:29282
[junit4:junit4]   2> 4270 T883 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:29282
[junit4:junit4]   2> 4273 T885 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8fb716530005 with negotiated timeout 20000 for client /140.211.11.196:29282
[junit4:junit4]   2> 4273 T920 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:29270, sessionid = 0x13d8fb716530005, negotiated timeout = 20000
[junit4:junit4]   2> 4273 T921 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@58d62cd8 name:ZooKeeperConnection Watcher:127.0.0.1:29270 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4273 T881 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4275 T886 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8fb716530005
[junit4:junit4]   2> 4289 T921 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 4289 T881 oaz.ZooKeeper.close Session: 0x13d8fb716530005 closed
[junit4:junit4]   2> 4289 T883 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:29282 which had sessionid 0x13d8fb716530005
[junit4:junit4]   2> 4289 T881 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 4301 T881 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:29270/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@48642c32
[junit4:junit4]   2> 4320 T922 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:29270. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 4319 T881 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 4320 T922 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:29270, initiating session
[junit4:junit4]   2> 4320 T883 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:29283
[junit4:junit4]   2> 4321 T883 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:29283
[junit4:junit4]   2> 4323 T885 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8fb716530006 with negotiated timeout 20000 for client /140.211.11.196:29283
[junit4:junit4]   2> 4323 T922 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:29270, sessionid = 0x13d8fb716530006, negotiated timeout = 20000
[junit4:junit4]   2> 4323 T923 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@48642c32 name:ZooKeeperConnection Watcher:127.0.0.1:29270/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 4324 T881 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 4325 T886 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8fb716530006 type:create cxid:0x1 zxid:0x48 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4327 T886 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8fb716530006 type:create cxid:0x3 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 4335 T881 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 5338 T881 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:29281_
[junit4:junit4]   2> 5340 T886 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8fb716530006 type:delete cxid:0xd zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:29281_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:29281_
[junit4:junit4]   2> 5341 T881 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:29281_
[junit4:junit4]   2> 5344 T903 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> 5345 T923 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5345 T910 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5346 T903 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4]   2> 5362 T924 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty1-1363915777452/collection1
[junit4:junit4]   2> 5362 T904 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 5362 T924 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 5363 T904 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:29273__collection1",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"control_collection",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:29273_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:29273"}
[junit4:junit4]   2> 5363 T924 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 5363 T924 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 5365 T924 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty1-1363915777452/collection1/'
[junit4:junit4]   2> 5366 T924 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty1-1363915777452/collection1/lib/README' to classloader
[junit4:junit4]   2> 5367 T924 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty1-1363915777452/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 5400 T903 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> 5400 T923 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> 5400 T910 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> 5418 T924 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_43
[junit4:junit4]   2> 5477 T924 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 5578 T924 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 5585 T924 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 6222 T924 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 6234 T924 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 6238 T924 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 6254 T924 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 6260 T924 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 6264 T924 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 6265 T924 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 6267 T924 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 6267 T924 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 6268 T924 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 6268 T924 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 6269 T924 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 6269 T924 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty1-1363915777452/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1363915773517/jetty1/
[junit4:junit4]   2> 6269 T924 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@bb933cb
[junit4:junit4]   2> 6270 T924 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 6271 T924 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1363915773517/jetty1
[junit4:junit4]   2> 6271 T924 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1363915773517/jetty1/index/
[junit4:junit4]   2> 6272 T924 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1363915773517/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 6273 T924 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1363915773517/jetty1/index
[junit4:junit4]   2> 6279 T924 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1363915773517/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@6dc58d43; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 6279 T924 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 6282 T924 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 6282 T924 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 6283 T924 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 6284 T924 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 6284 T924 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 6285 T924 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 6285 T924 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 6286 T924 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 6286 T924 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 6298 T924 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 6306 T924 oass.SolrIndexSearcher.<init> Opening Searcher@2b2c0334 main
[junit4:junit4]   2> 6307 T924 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 6307 T924 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 6311 T925 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2b2c0334 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 6314 T924 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 6314 T924 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 6905 T904 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 6906 T904 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> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:29281_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:29281"}
[junit4:junit4]   2> 6906 T904 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 1
[junit4:junit4]   2> 6906 T904 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 6911 T903 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> 6911 T923 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> 6911 T910 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> 7317 T924 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 7317 T924 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:29281 collection:collection1 shard:shard1
[junit4:junit4]   2> 7318 T924 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4]   2> 7397 T886 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8fb716530006 type:delete cxid:0x4a zxid:0x5a txntype:-1 reqpath:n/a Error Path:/solr/collections/collection1/leaders Error:KeeperErrorCode = NoNode for /solr/collections/collection1/leaders
[junit4:junit4]   2> 7422 T924 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4]   2> 7423 T886 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8fb716530006 type:create cxid:0x4b zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 7440 T924 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4]   2> 7440 T924 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4]   2> 7441 T924 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:29281/collection1/
[junit4:junit4]   2> 7441 T924 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4]   2> 7441 T924 oasc.SyncStrategy.syncToMe http://127.0.0.1:29281/collection1/ has no replicas
[junit4:junit4]   2> 7441 T924 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:29281/collection1/
[junit4:junit4]   2> 7441 T924 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4]   2> 7445 T886 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8fb716530006 type:create cxid:0x56 zxid:0x5f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8428 T904 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8471 T903 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> 8471 T923 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> 8471 T910 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> 8520 T924 oasc.ZkController.register We are http://127.0.0.1:29281/collection1/ and leader is http://127.0.0.1:29281/collection1/
[junit4:junit4]   2> 8520 T924 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:29281
[junit4:junit4]   2> 8520 T924 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4]   2> 8520 T924 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4]   2> 8520 T924 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 8523 T924 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 8523 T881 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1
[junit4:junit4]   2> 8524 T881 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 8524 T881 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 8665 T881 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 8668 T881 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:29291
[junit4:junit4]   2> 8668 T881 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 8669 T881 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 8669 T881 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1363915782047
[junit4:junit4]   2> 8669 T881 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1363915782047/solr.xml
[junit4:junit4]   2> 8669 T881 oasc.CoreContainer.<init> New CoreContainer 22354617
[junit4:junit4]   2> 8670 T881 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1363915782047/'
[junit4:junit4]   2> 8670 T881 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1363915782047/'
[junit4:junit4]   2> 8713 T881 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 8714 T881 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 8714 T881 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 8714 T881 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 8715 T881 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 8715 T881 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 8715 T881 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 8716 T881 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 8716 T881 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 8716 T881 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 8732 T881 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 8745 T881 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:29270/solr
[junit4:junit4]   2> 8746 T881 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 8746 T881 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:29270 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@3dc158dc
[junit4:junit4]   2> 8747 T881 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8747 T936 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:29270. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 8748 T936 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:29270, initiating session
[junit4:junit4]   2> 8748 T883 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:29292
[junit4:junit4]   2> 8749 T883 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:29292
[junit4:junit4]   2> 8751 T885 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8fb716530007 with negotiated timeout 20000 for client /140.211.11.196:29292
[junit4:junit4]   2> 8751 T936 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:29270, sessionid = 0x13d8fb716530007, negotiated timeout = 20000
[junit4:junit4]   2> 8751 T937 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3dc158dc name:ZooKeeperConnection Watcher:127.0.0.1:29270 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8751 T881 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8752 T886 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8fb716530007
[junit4:junit4]   2> 8764 T937 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 8764 T883 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:29292 which had sessionid 0x13d8fb716530007
[junit4:junit4]   2> 8764 T881 oaz.ZooKeeper.close Session: 0x13d8fb716530007 closed
[junit4:junit4]   2> 8764 T881 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 8773 T881 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:29270/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@4e264d7e
[junit4:junit4]   2> 8774 T881 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 8774 T938 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:29270. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 8775 T938 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:29270, initiating session
[junit4:junit4]   2> 8775 T883 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:29293
[junit4:junit4]   2> 8775 T883 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:29293
[junit4:junit4]   2> 8776 T885 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8fb716530008 with negotiated timeout 20000 for client /140.211.11.196:29293
[junit4:junit4]   2> 8776 T938 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:29270, sessionid = 0x13d8fb716530008, negotiated timeout = 20000
[junit4:junit4]   2> 8777 T939 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4e264d7e name:ZooKeeperConnection Watcher:127.0.0.1:29270/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 8777 T881 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 8777 T886 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8fb716530008 type:create cxid:0x1 zxid:0x6c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8783 T886 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8fb716530008 type:create cxid:0x3 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 8785 T881 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 9788 T881 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:29291_
[junit4:junit4]   2> 9789 T886 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8fb716530008 type:delete cxid:0xd zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:29291_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:29291_
[junit4:junit4]   2> 9790 T881 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:29291_
[junit4:junit4]   2> 9792 T910 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> 9792 T903 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> 9792 T923 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> 9794 T939 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9795 T910 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9795 T923 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9795 T903 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4]   2> 9812 T940 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1363915782047/collection1
[junit4:junit4]   2> 9813 T940 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 9813 T940 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 9813 T940 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 9815 T940 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1363915782047/collection1/'
[junit4:junit4]   2> 9815 T940 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty2-1363915782047/collection1/lib/README' to classloader
[junit4:junit4]   2> 9816 T940 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty2-1363915782047/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 9851 T940 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_43
[junit4:junit4]   2> 9892 T940 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 9988 T904 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 9989 T904 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:29281__collection1",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"active",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:29281_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:29281"}
[junit4:junit4]   2> 9993 T940 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 9998 T940 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 10008 T903 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> 10008 T910 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> 10008 T923 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> 10008 T939 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> 10437 T940 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 10446 T940 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 10449 T940 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 10461 T940 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 10465 T940 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 10469 T940 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 10470 T940 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 10471 T940 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 10471 T940 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 10472 T940 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 10472 T940 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 10472 T940 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 10472 T940 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty2-1363915782047/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1363915773517/jetty2/
[junit4:junit4]   2> 10473 T940 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@bb933cb
[junit4:junit4]   2> 10473 T940 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 10474 T940 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1363915773517/jetty2
[junit4:junit4]   2> 10474 T940 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1363915773517/jetty2/index/
[junit4:junit4]   2> 10474 T940 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1363915773517/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 10475 T940 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1363915773517/jetty2/index
[junit4:junit4]   2> 10480 T940 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1363915773517/jetty2/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@13d6674c; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 10480 T940 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 10482 T940 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 10482 T940 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 10483 T940 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 10483 T940 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 10484 T940 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 10484 T940 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 10484 T940 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 10485 T940 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 10485 T940 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 10493 T940 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 10499 T940 oass.SolrIndexSearcher.<init> Opening Searcher@183ea8d main
[junit4:junit4]   2> 10500 T940 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 10500 T940 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 10503 T941 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@183ea8d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 10505 T940 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 10505 T940 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 11513 T904 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 11514 T904 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> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:29291_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:29291"}
[junit4:junit4]   2> 11514 T904 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4]   2> 11514 T904 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4]   2> 11519 T903 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> 11519 T910 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> 11519 T939 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> 11519 T923 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> 12509 T940 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4]   2> 12509 T940 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:29291 collection:collection1 shard:shard1
[junit4:junit4]   2> 12517 T940 oasc.ZkController.register We are http://127.0.0.1:29291/collection1/ and leader is http://127.0.0.1:29281/collection1/
[junit4:junit4]   2> 12518 T940 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:29291
[junit4:junit4]   2> 12518 T940 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4]   2> 12518 T940 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4]   2> ASYNC  NEW_CORE C46 name=collection1 org.apache.solr.core.SolrCore@4c0e4a2b url=http://127.0.0.1:29291/collection1 node=127.0.0.1:29291_ C46_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:29291_, base_url=http://127.0.0.1:29291}
[junit4:junit4]   2> 12526 T942 C46 P29291 oasc.RecoveryStrategy.run Starting recovery process.  core=collection1 recoveringAfterStartup=true
[junit4:junit4]   2> 12526 T940 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 12527 T942 C46 P29291 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4]   2> 12528 T942 C46 P29291 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4]   2> 12528 T942 C46 P29291 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2> 12528 T881 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1
[junit4:junit4]   2> 12529 T881 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4]   2> 12530 T881 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 12531 T942 C46 P29291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> 12772 T881 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4]   2> 12776 T881 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:29295
[junit4:junit4]   2> 12777 T881 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4]   2> 12777 T881 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4]   2> 12778 T881 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty3-1363915786065
[junit4:junit4]   2> 12778 T881 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty3-1363915786065/solr.xml
[junit4:junit4]   2> 12779 T881 oasc.CoreContainer.<init> New CoreContainer 1518344743
[junit4:junit4]   2> 12780 T881 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty3-1363915786065/'
[junit4:junit4]   2> 12780 T881 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty3-1363915786065/'
[junit4:junit4]   2> 12865 T881 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4]   2> 12866 T881 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4]   2> 12867 T881 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4]   2> 12867 T881 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4]   2> 12868 T881 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4]   2> 12869 T881 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4]   2> 12870 T881 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4]   2> 12870 T881 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4]   2> 12871 T881 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4]   2> 12872 T881 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4]   2> 12907 T881 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4]   2> 12935 T881 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:29270/solr
[junit4:junit4]   2> 12936 T881 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4]   2> 12937 T881 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:29270 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@3b902263
[junit4:junit4]   2> 12938 T881 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 12939 T953 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:29270. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 12940 T953 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:29270, initiating session
[junit4:junit4]   2> 12940 T883 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:29297
[junit4:junit4]   2> 12940 T883 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:29297
[junit4:junit4]   2> 12942 T885 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8fb716530009 with negotiated timeout 20000 for client /140.211.11.196:29297
[junit4:junit4]   2> 12942 T953 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:29270, sessionid = 0x13d8fb716530009, negotiated timeout = 20000
[junit4:junit4]   2> 12943 T954 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3b902263 name:ZooKeeperConnection Watcher:127.0.0.1:29270 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 12943 T881 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 12945 T886 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8fb716530009
[junit4:junit4]   2> 12953 T954 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 12953 T883 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:29297 which had sessionid 0x13d8fb716530009
[junit4:junit4]   2> 12953 T881 oaz.ZooKeeper.close Session: 0x13d8fb716530009 closed
[junit4:junit4]   2> 12954 T881 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4]   2> 12971 T881 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:29270/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@7058e3b9
[junit4:junit4]   2> 12973 T881 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4]   2> 12973 T955 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:29270. Will not attempt to authenticate using SASL (access denied ("javax.security.auth.AuthPermission" "getLoginConfiguration"))
[junit4:junit4]   2> 12974 T955 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:29270, initiating session
[junit4:junit4]   2> 12974 T883 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:29298
[junit4:junit4]   2> 12975 T883 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:29298
[junit4:junit4]   2> 12981 T885 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8fb71653000a with negotiated timeout 20000 for client /140.211.11.196:29298
[junit4:junit4]   2> 12981 T955 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:29270, sessionid = 0x13d8fb71653000a, negotiated timeout = 20000
[junit4:junit4]   2> 12981 T956 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7058e3b9 name:ZooKeeperConnection Watcher:127.0.0.1:29270/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4]   2> 12981 T881 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4]   2> 12983 T886 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8fb71653000a type:create cxid:0x1 zxid:0x7f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12985 T886 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8fb71653000a type:create cxid:0x3 zxid:0x80 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4]   2> 12994 T881 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper... 
[junit4:junit4]   2> 13039 T904 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper... 
[junit4:junit4]   2> 13040 T904 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4]   2> 	  "operation":"state",
[junit4:junit4]   2> 	  "core_node_name":"127.0.0.1:29291__collection1",
[junit4:junit4]   2> 	  "numShards":"1",
[junit4:junit4]   2> 	  "shard":"shard1",
[junit4:junit4]   2> 	  "roles":null,
[junit4:junit4]   2> 	  "state":"recovering",
[junit4:junit4]   2> 	  "core":"collection1",
[junit4:junit4]   2> 	  "collection":"collection1",
[junit4:junit4]   2> 	  "node_name":"127.0.0.1:29291_",
[junit4:junit4]   2> 	  "base_url":"http://127.0.0.1:29291"}
[junit4:junit4]   2> 13053 T903 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> 13053 T923 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> 13053 T910 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> 13053 T956 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> 13053 T939 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> 13571 T913 oass.SolrDispatchFilter.handleAdminRequest /admin/cores {coreNodeName=127.0.0.1:29291__collection1&state=recovering&nodeName=127.0.0.1:29291_&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1007 
[junit4:junit4]   2> 13999 T881 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:29295_
[junit4:junit4]   2> 14000 T886 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8fb71653000a type:delete cxid:0xf zxid:0x85 txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:29295_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:29295_
[junit4:junit4]   2> 14030 T881 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:29295_
[junit4:junit4]   2> 14033 T903 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> 14033 T910 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> 14033 T923 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> 14034 T956 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14034 T939 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14034 T956 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> 14035 T939 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> 14036 T903 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14036 T923 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14036 T910 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4]   2> 14053 T957 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty3-1363915786065/collection1
[junit4:junit4]   2> 14053 T957 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4]   2> 14054 T957 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4]   2> 14054 T957 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4]   2> 14056 T957 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty3-1363915786065/collection1/'
[junit4:junit4]   2> 14057 T957 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty3-1363915786065/collection1/lib/classes/' to classloader
[junit4:junit4]   2> 14058 T957 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-jetty3-1363915786065/collection1/lib/README' to classloader
[junit4:junit4]   2> 14108 T957 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_43
[junit4:junit4]   2> 14198 T957 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4]   2> 14299 T957 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4]   2> 14311 T957 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4]   2> 15116 T957 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4]   2> 15132 T957 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4]   2> 15136 T957 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4]   2> 15153 T957 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 15158 T957 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4]   2> 15162 T957 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 15163 T957 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 15164 T957 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 15164 T957 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4]   2> 15165 T957 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4]   2> 15166 T957 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4]   2> 15166 T957 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 15166 T957 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/./org.apache.solr.cloud.SyncSliceTest-jetty3-1363915786065/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1363915773517/jetty3/
[junit4:junit4]   2> 15167 T957 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@bb933cb
[junit4:junit4]   2> 15167 T957 oasc.SolrCore.initDirectoryFactory solr.NRTCachingDirectoryFactory
[junit4:junit4]   2> 15168 T957 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1363915773517/jetty3
[junit4:junit4]   2> 15169 T957 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1363915773517/jetty3/index/
[junit4:junit4]   2> 15169 T957 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1363915773517/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4]   2> 15170 T957 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1363915773517/jetty3/index
[junit4:junit4]   2> 15175 T957 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1363915773517/jetty3/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@5e173225; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 15176 T957 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 15179 T957 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4]   2> 15179 T957 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4]   2> 15180 T957 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4]   2> 15180 T957 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4]   2> 15181 T957 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4]   2> 15181 T957 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4]   2> 15181 T957 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4]   2> 15182 T957 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4]   2> 15182 T957 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4]   2> 15194 T957 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4]   2> 15202 T957 oass.SolrIndexSearcher.<init> Opening Searcher@323f9af6 main
[junit4:junit4]   2> 15203 T957 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4]   2> 15203 T957 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4]   2> 15207 T958 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@323f9af6 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4]   2> 15209 T957 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4]   2> 15210 T957 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4]   2>  C46_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:29291_, base_url=http://127.0.0.1:29291}
[junit4:junit4]   2> 15573 T942 C46 P29291 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:29281/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4]   2> 15573 T942 C46 P29291 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:29291 START replicas=[http://127.0.0.1:29281/collection1/] nUpdates=100
[junit4:junit4]   2> 15574 T942 C46 P29291 oasu.PeerSync.sync WARNING no frame of reference to tell of we've missed updates
[junit4:junit4]   2> 15574 T942 C46 P29291 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4]   2> 15575 T942 C46 P29291 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4]   2> 15575 T942 C46 P29291 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4]   2> 15575 T942 C46 P29291 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4]   2> 15575 T942 C46 P29291 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:29281/collection1/. core=collection1
[junit4:junit4]   2> 15575 T942 C46 P29291 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4]   2> ASYNC  NEW_CORE C47 name=collection1 org.apache.solr.core.SolrCore@762969ac url=http://127.0.0.1:29281/collection1 node=127.0.0.1:29281_ C47_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:29281_, base_url=http://127.0.0.1:29281, leader=true}
[junit4:junit4]   2> 15583 T914 C47 P29281 REQ /get {getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0 
[junit4:junit4]   2> 15611 T915 C47 P29281 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4]   2> 15616 T915 C47 P29281 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1363915773517/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@6dc58d43; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 15617 T915 C47 P29281 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4]   2> 15621 T915 C47 P29281 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1363915773517/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@6dc58d43; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4]   2> 		commit{dir=NRTCachingDirectory(org.apache.lucene.store.NIOFSDirectory@/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/build/solr-core/test/J1/org.apache.solr.cloud.SyncSliceTest-1363915773517/jetty1/index lockFactory=org.apache.lucene.store.NativeFSLockFactory@6dc58d43; maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_2,generation=2,filenames=[segments_2]
[junit4:junit4]   2> 15622 T915 C47 P29281 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[segments_2]
[junit4:junit4]   2> 15623 T915 C47 P29281 oass.SolrIndexSearcher.<init> Opening Searcher@14d1d347 realtime
[junit4:junit4]   2> 15624 T915 C47 P29281 oasu.DirectUpdateHandler2.commit

[...truncated too long message...]

2> 141789 T883 oazs.NIOServerCnxnFactory.run NIOServerCnxn factory exited run method
[junit4:junit4]   2> 141789 T956 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4]   2> 141790 T881 oazs.ZooKeeperServer.shutdown shutting down
[junit4:junit4]   2> 141791 T881 oazs.SessionTrackerImpl.shutdown Shutting down
[junit4:junit4]   2> 141791 T881 oazs.PrepRequestProcessor.shutdown Shutting down
[junit4:junit4]   2> 141792 T881 oazs.SyncRequestProcessor.shutdown Shutting down
[junit4:junit4]   2> 141792 T881 oazs.FinalRequestProcessor.shutdown shutdown of request processor complete
[junit4:junit4]   1> client port:0.0.0.0/0.0.0.0:0
[junit4:junit4]   2> NOTE: reproduce with: ant test  -Dtestcase=SyncSliceTest -Dtests.method=testDistribSearch -Dtests.seed=9A03EFD7AD17965C -Dtests.multiplier=3 -Dtests.slow=true -Dtests.locale=ar_IQ -Dtests.timezone=Africa/Ouagadougou -Dtests.file.encoding=ISO-8859-1
[junit4:junit4] FAILURE  142s J1 | SyncSliceTest.testDistribSearch <<<
[junit4:junit4]    > Throwable #1: java.lang.AssertionError: Test Setup Failure: shard1 should have just been set up to be inconsistent - but it's still consistent. Leader:http://127.0.0.1:29291/collection1 Dead Guy:http://127.0.0.1:29281/collection1skip list:[CloudJettyRunner [url=http://127.0.0.1:29310/collection1], CloudJettyRunner [url=http://127.0.0.1:29310/collection1]]
[junit4:junit4]    > 	at __randomizedtesting.SeedInfo.seed([9A03EFD7AD17965C:1BE561CFDA48F660]:0)
[junit4:junit4]    > 	at org.junit.Assert.fail(Assert.java:93)
[junit4:junit4]    > 	at org.junit.Assert.assertTrue(Assert.java:43)
[junit4:junit4]    > 	at org.junit.Assert.assertNotNull(Assert.java:526)
[junit4:junit4]    > 	at org.apache.solr.cloud.SyncSliceTest.doTest(SyncSliceTest.java:212)
[junit4:junit4]    > 	at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:806)
[junit4:junit4]    > 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
[junit4:junit4]    > 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
[junit4:junit4]    > 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
[junit4:junit4]    > 	at java.lang.reflect.Method.invoke(Method.java:601)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
[junit4:junit4]    > 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
[junit4:junit4]    > 	at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
[junit4:junit4]    > 	at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
[junit4:junit4]    > 	at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
[junit4:junit4]    > 	at java.lang.Thread.run(Thread.java:722)
[junit4:junit4]   2> 141814 T881 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4]   2> NOTE: test params are: codec=SimpleText, sim=RandomSimilarityProvider(queryNorm=true,coord=crazy): {}, locale=ar_IQ, timezone=Africa/Ouagadougou
[junit4:junit4]   2> NOTE: FreeBSD 9.0-RELEASE amd64/Oracle Corporation 1.7.0_17 (64-bit)/cpus=16,threads=5,free=65603768,total=439353344
[junit4:junit4]   2> NOTE: All tests run in this JVM: [JSONWriterTest, SchemaVersionSpecificBehaviorTest, TestDocSet, UUIDFieldTest, TestBadConfig, TestTrie, StatsComponentTest, TestSolrJ, TestArbitraryIndexDir, SimpleFacetsTest, TestSolrCoreProperties, SignatureUpdateProcessorFactoryTest, SolrIndexSplitterTest, FieldAnalysisRequestHandlerTest, AlternateDirectoryTest, TestLMDirichletSimilarityFactory, TestJmxMonitoredMap, TestOmitPositions, TestFastWriter, BasicFunctionalityTest, SpellCheckComponentTest, OverseerCollectionProcessorTest, TestFastOutputStream, AnalysisAfterCoreReloadTest, BadIndexSchemaTest, TestSweetSpotSimilarityFactory, SortByFunctionTest, HighlighterConfigTest, TestFoldingMultitermQuery, IndexReaderFactoryTest, TestIndexSearcher, TestShardHandlerFactory, CoreContainerCoreInitFailuresTest, SampleTest, TestStressVersions, TestPerFieldSimilarity, DefaultValueUpdateProcessorTest, TestAtomicUpdateErrorCases, SuggesterWFSTTest, DocumentBuilderTest, TestPostingsSolrHighlighter, PeerSyncTest, StatelessScriptUpdateProcessorFactoryTest, TestBinaryResponseWriter, TestPHPSerializedResponseWriter, ClusterStateUpdateTest, TestSolrQueryParser, PrimUtilsTest, TestSuggestSpellingConverter, TestUtils, DOMUtilTest, IndexSchemaRuntimeFieldTest, TestDynamicFieldCollectionResource, AutoCommitTest, TestStressReorder, TestSolrIndexConfig, TestCollationKeyRangeQueries, ZkControllerTest, TestGroupingSearch, QueryParsingTest, LeaderElectionTest, DistributedQueryElevationComponentTest, SolrRequestParserTest, SliceStateUpdateTest, TestFieldResource, TermVectorComponentTest, SyncSliceTest]
[junit4:junit4] Completed on J1 in 141.84s, 1 test, 1 failure <<< FAILURES!

[...truncated 531 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/build.xml:381: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/build.xml:361: 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:183: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/solr/common-build.xml:449: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/common-build.xml:1213: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-java7/lucene/common-build.xml:877: There were test failures: 273 suites, 1148 tests, 2 failures, 27 ignored (8 assumptions)

Total time: 50 minutes 56 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure



Mime
View raw message