You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2013/03/21 11:51:21 UTC
[JENKINS] Lucene-Solr-NightlyTests-4.2.1 - Build # 2 - Failure
Build: https://builds.apache.org/job/Lucene-Solr-NightlyTests-4.2.1/2/
2 tests failed.
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:26777/collection1skip list:[CloudJettyRunner [url=http://127.0.0.1:26811/collection1], CloudJettyRunner [url=http://127.0.0.1:26820/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:26777/collection1skip list:[CloudJettyRunner [url=http://127.0.0.1:26811/collection1], CloudJettyRunner [url=http://127.0.0.1:26820/collection1]]
at __randomizedtesting.SeedInfo.seed([80AB1224E117CA42:14D9C3C9648AA7E]: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:616)
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:679)
FAILED: org.apache.solr.update.SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds
Error Message:
searcher529 wasn't soon enough after soft529: 1363861548737 !< 1363861548492 + 228 (fudge)
Stack Trace:
java.lang.AssertionError: searcher529 wasn't soon enough after soft529: 1363861548737 !< 1363861548492 + 228 (fudge)
at __randomizedtesting.SeedInfo.seed([80AB1224E117CA42:D17FEBA45064FAE5]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.apache.solr.update.SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds(SoftAutoCommitTest.java:137)
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:616)
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:679)
Build Log:
[...truncated 8426 lines...]
[junit4:junit4] Suite: org.apache.solr.update.SoftAutoCommitTest
[junit4:junit4] 2> 1 T36 oas.SolrTestCaseJ4.initCore ####initCore
[junit4:junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J1/./solrtest-SoftAutoCommitTest-1363861546645
[junit4:junit4] 2> 1 T36 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4] 2> 2 T36 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4] 2> 3 T36 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 56 T36 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 106 T36 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 107 T36 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 113 T36 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 569 T36 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 578 T36 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 581 T36 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 594 T36 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 598 T36 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 601 T36 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 602 T36 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 602 T36 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 603 T36 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 603 T36 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 603 T36 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 604 T36 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 604 T36 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr
[junit4:junit4] 2> 604 T36 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/'
[junit4:junit4] 2> 613 T36 oasc.CoreContainer.<init> New CoreContainer 2083573092
[junit4:junit4] 2> 614 T36 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 614 T36 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J1/./solrtest-SoftAutoCommitTest-1363861546645/
[junit4:junit4] 2> 615 T36 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@63f8247d
[junit4:junit4] 2> 616 T36 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 617 T36 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J1/./solrtest-SoftAutoCommitTest-1363861546645 forceNew: false
[junit4:junit4] 2> 617 T36 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J1/./solrtest-SoftAutoCommitTest-1363861546645/index/
[junit4:junit4] 2> 618 T36 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J1/./solrtest-SoftAutoCommitTest-1363861546645/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 618 T36 oasc.CachingDirectoryFactory.get return new directory for /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J1/./solrtest-SoftAutoCommitTest-1363861546645/index forceNew: false
[junit4:junit4] 2> 620 T36 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@2207d8bb lockFactory=org.apache.lucene.store.NativeFSLockFactory@45a8123b)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 621 T36 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 621 T36 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4] 2> 623 T36 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 623 T36 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4] 2> 624 T36 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 624 T36 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4] 2> 625 T36 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 625 T36 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 625 T36 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 626 T36 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 627 T36 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 627 T36 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4] 2> 628 T36 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4] 2> 628 T36 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 629 T36 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 629 T36 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 629 T36 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 630 T36 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 630 T36 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 631 T36 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 631 T36 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 632 T36 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 632 T36 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 633 T36 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 633 T36 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 634 T36 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 634 T36 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4] 2> 635 T36 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4] 2> 640 T36 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 643 T36 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4] 2> 644 T36 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [THROW.ERROR.ON.ADD.UPDATEPROCESSOR.JS, SOLRCONFIG-HIGHLIGHT.XML, SCHEMA-REQUIRED-FIELDS.XML, TRIVIAL.UPDATEPROCESSOR1.JS, SCHEMA-MINIMAL.XML, BAD-SCHEMA-DUP-DYNAMICFIELD.XML, SCHEMA-REPLICATION2.XML, BAD-SCHEMA-DOCVALUES-NOT-REQUIRED-NO-DEFAULT.XML, SOLRCONFIG-CACHING.XML, SCHEMA-POSTINGSHIGHLIGHT.XML, SOLRCONFIG-REPEATER.XML, REGEX-BOOST-PROCESSOR-TEST.TXT, BAD-SCHEMA-NONTEXT-ANALYZER.XML, BAD-SCHEMA-CURRENCY-FT-BOGUS-CODE-IN-XML.XML, SOLRCONFIG-MERGEPOLICY.XML, CURRENCY.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-IB.XML, SCHEMA-CHARFILTERS.XML, SOLRCONFIG-QUERYSENDER.XML, SCHEMA-REPLICATION1.XML, SOLRCONFIG-SNIPPET-PROCESSOR.XML, DA_UTF8.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, SCHEMA-REVERSED.XML, STOPTYPES-2.TXT, BAD-SCHEMA-CURRENCY-FT-MULTIVALUED.XML, SOLRCONFIG-SPELLCHECKCOMPONENT.XML, SCHEMA-DFR.XML, BAD-SCHEMA-CURRENCY-MULTIVALUED.XML, SOLRCONFIG-PHRASESUGGEST.XML, BAD-SCHEMA-NOT-INDEXED-BUT-POS.XML, KEEP-1.TXT, SCHEMA-SPATIAL.XML, OPEN-EXCHANGE-RATES.JSON, STOPWITHBOM.TXT, SOLRCONFIG-SPELLCHECKER.XML, SOLRCONFIG-POSTINGSHIGHLIGHT.XML, SCHEMA-BINARYFIELD.XML, SOLRCONFIG-UPDATE-PROCESSOR-CHAINS.XML, BAD-SCHEMA-OMIT-TF-BUT-NOT-POS.XML, BAD-SCHEMA-DUP-FIELDTYPE.XML, SCHEMA-XINCLUDE.XML, SOLRCONFIG-MASTER1.XML, SCHEMA-BEHAVIOR.XML, SYNONYMS.TXT, 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, SOLRCONFIG-TERMINDEX.XML, SCHEMA-LMDIRICHLET.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-DELPOLICY1.XML, SOLRCONFIG-SLAVE1.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-QUERYSENDER-NOQUERY.XML, SOLRCONFIG-ALTDIRECTORY.XML, COMPOUNDDICTIONARY.TXT, BAD-SCHEMA-CURRENCY-FT-BOGUS-DEFAULT-CODE.XML, BAD-CURRENCY.XML, SOLRCONFIG_PERF.XML, SOLRCONFIG-INDEXCONFIG.XML, SCHEMA-NOT-REQUIRED-UNIQUE-KEY.XML, BAD-SCHEMA-ANALYZER-CLASS-AND-NESTED.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> 647 T36 oass.SolrIndexSearcher.<init> Opening Searcher@25b8737f main
[junit4:junit4] 2> 647 T36 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 648 T36 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 648 T36 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4] 2> 658 T36 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4] 2> 707 T37 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@25b8737f main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 711 T36 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 716 T36 oas.SolrTestCaseJ4.initCore ####initCore end
[junit4:junit4] 2> 719 T36 oas.SolrTestCaseJ4.setUp ###Starting testSoftAndHardCommitMaxTimeMixedAdds
[junit4:junit4] 2> 720 T36 oasc.CoreContainer.reload Reloading SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4] 2> 720 T36 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4] 2> 721 T36 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4] 2> 722 T36 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 772 T36 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 820 T36 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 821 T36 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 825 T36 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 1236 T36 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1245 T36 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1247 T36 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1260 T36 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1264 T36 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1267 T36 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1267 T36 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1268 T36 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 1268 T36 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1268 T36 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1269 T36 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 1269 T36 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J1/./solrtest-SoftAutoCommitTest-1363861546645/
[junit4:junit4] 2> 1270 T36 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@63f8247d
[junit4:junit4] 2> 1270 T36 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J1/./solrtest-SoftAutoCommitTest-1363861546645/index/
[junit4:junit4] 2> 1271 T36 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4] 2> 1272 T36 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1273 T36 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4] 2> 1273 T36 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1274 T36 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4] 2> 1274 T36 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1274 T36 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1275 T36 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1276 T36 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1276 T36 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1277 T36 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4] 2> 1277 T36 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4] 2> 1278 T36 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1278 T36 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 1279 T36 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 1279 T36 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 1280 T36 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1280 T36 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1281 T36 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1282 T36 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1282 T36 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1283 T36 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1283 T36 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1284 T36 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1285 T36 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 1285 T36 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4] 2> 1286 T36 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4] 2> 1287 T36 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1289 T36 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4] 2> 1290 T36 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [THROW.ERROR.ON.ADD.UPDATEPROCESSOR.JS, SOLRCONFIG-HIGHLIGHT.XML, SCHEMA-REQUIRED-FIELDS.XML, TRIVIAL.UPDATEPROCESSOR1.JS, SCHEMA-MINIMAL.XML, BAD-SCHEMA-DUP-DYNAMICFIELD.XML, SCHEMA-REPLICATION2.XML, BAD-SCHEMA-DOCVALUES-NOT-REQUIRED-NO-DEFAULT.XML, SOLRCONFIG-CACHING.XML, SCHEMA-POSTINGSHIGHLIGHT.XML, SOLRCONFIG-REPEATER.XML, REGEX-BOOST-PROCESSOR-TEST.TXT, BAD-SCHEMA-NONTEXT-ANALYZER.XML, BAD-SCHEMA-CURRENCY-FT-BOGUS-CODE-IN-XML.XML, SOLRCONFIG-MERGEPOLICY.XML, CURRENCY.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-IB.XML, SCHEMA-CHARFILTERS.XML, SOLRCONFIG-QUERYSENDER.XML, SCHEMA-REPLICATION1.XML, SOLRCONFIG-SNIPPET-PROCESSOR.XML, DA_UTF8.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, SCHEMA-REVERSED.XML, STOPTYPES-2.TXT, BAD-SCHEMA-CURRENCY-FT-MULTIVALUED.XML, SOLRCONFIG-SPELLCHECKCOMPONENT.XML, SCHEMA-DFR.XML, BAD-SCHEMA-CURRENCY-MULTIVALUED.XML, SOLRCONFIG-PHRASESUGGEST.XML, BAD-SCHEMA-NOT-INDEXED-BUT-POS.XML, KEEP-1.TXT, SCHEMA-SPATIAL.XML, OPEN-EXCHANGE-RATES.JSON, STOPWITHBOM.TXT, SOLRCONFIG-SPELLCHECKER.XML, SOLRCONFIG-POSTINGSHIGHLIGHT.XML, SCHEMA-BINARYFIELD.XML, SOLRCONFIG-UPDATE-PROCESSOR-CHAINS.XML, BAD-SCHEMA-OMIT-TF-BUT-NOT-POS.XML, BAD-SCHEMA-DUP-FIELDTYPE.XML, SCHEMA-XINCLUDE.XML, SOLRCONFIG-MASTER1.XML, SCHEMA-BEHAVIOR.XML, SYNONYMS.TXT, 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, SOLRCONFIG-TERMINDEX.XML, SCHEMA-LMDIRICHLET.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-DELPOLICY1.XML, SOLRCONFIG-SLAVE1.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-QUERYSENDER-NOQUERY.XML, SOLRCONFIG-ALTDIRECTORY.XML, COMPOUNDDICTIONARY.TXT, BAD-SCHEMA-CURRENCY-FT-BOGUS-DEFAULT-CODE.XML, BAD-CURRENCY.XML, SOLRCONFIG_PERF.XML, SOLRCONFIG-INDEXCONFIG.XML, SCHEMA-NOT-REQUIRED-UNIQUE-KEY.XML, BAD-SCHEMA-ANALYZER-CLASS-AND-NESTED.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> 1293 T36 oass.SolrIndexSearcher.<init> Opening Searcher@7fdb04ed main
[junit4:junit4] 2> 1293 T36 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1294 T36 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1294 T36 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4] 2> 1296 T36 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4] 2> 1308 T38 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7fdb04ed main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1318 T36 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 1318 T36 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 1320 T36 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@2207d8bb lockFactory=org.apache.lucene.store.NativeFSLockFactory@45a8123b)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 1320 T36 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 1321 T36 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 1321 T36 oass.SolrIndexSearcher.<init> Opening Searcher@373ee92 main
[junit4:junit4] 2> 1321 T36 oasc.CoreContainer.registerCore replacing core: collection1
[junit4:junit4] 2> 1322 T36 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@67fc9fee
[junit4:junit4] 2> 1323 T38 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@373ee92 main{StandardDirectoryReader(segments_1:1:nrt)}
[junit4:junit4] 2> 1328 T36 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> 1329 T36 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> ASYNC NEW_CORE C7 name=collection1 org.apache.solr.core.SolrCore@49af7e68
[junit4:junit4] 2> 1347 T36 C7 UPDATE [collection1] webapp=null path=null params={} {add=[529]} 0 13
[junit4:junit4] 2> 1848 T40 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4:junit4] 2> 2092 T40 oass.SolrIndexSearcher.<init> Opening Searcher@63fa8d3b main
[junit4:junit4] 2> 2092 T40 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2094 T38 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@63fa8d3b main{StandardDirectoryReader(segments_1:3:nrt _0(4.2.1):C1)}
[junit4:junit4] 2> 2104 T36 C7 UPDATE [collection1] webapp=null path=null params={} {add=[530]} 0 2
[junit4:junit4] 2> 2548 T39 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 2557 T39 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@2207d8bb lockFactory=org.apache.lucene.store.NativeFSLockFactory@45a8123b)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@2207d8bb lockFactory=org.apache.lucene.store.NativeFSLockFactory@45a8123b)),segFN=segments_2,generation=2,filenames=[_1_NestedPulsing_0.tip, _1_Lucene41_0.doc, _0_Lucene41_0.pos, _1_MockFixedIntBlock_0.pyl, _0_MockFixedIntBlock_0.tib, _1.fnm, _1_MockRandom_0.pos, _0_NestedPulsing_0.pos, _0_MockFixedIntBlock_0.tii, _1_NestedPulsing_0.tim, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _0_NestedPulsing_0.doc, _1.nvm, _0.fnm, _1_MockFixedIntBlock_0.frq, _1_MockRandom_0.tip, _1.nvd, _1_NestedPulsing_0.pos, _0_MockFixedIntBlock_0.pos, _1_MockRandom_0.sd, _1_MockRandom_0.tim, _0_MockRandom_0.skp, _1.fdx, _1_Lucene41_0.pos, _0_MockRandom_0.frq, _1_MockFixedIntBlock_0.skp, _1.fdt, _0_Lucene41_0.doc, _0_MockRandom_0.doc, _0_MockRandom_0.pos, _1_MockRandom_0.doc, _1_MockFixedIntBlock_0.pos, _1_MockRandom_0.frq, _1_MockFixedIntBlock_0.doc, _0_NestedPulsing_0.tip, _0_NestedPulsing_0.tim, _1_NestedPulsing_0.doc, _0_MockFixedIntBlock_0.pyl, _0_MockFixedIntBlock_0.skp, _0.nvd, _0.si, _0_MockRandom_0.tib, _1_MockFixedIntBlock_0.tii, _1_Lucene41_0.tim, _1_Lucene41_0.tip, _1_MockRandom_0.skp, _0.nvm, _0_MockFixedIntBlock_0.frq, _0_MockRandom_0.sd, _1_MockRandom_0.pyl, _0_MockRandom_0.tiv, _0_MockFixedIntBlock_0.doc, _1.si, _1_MockFixedIntBlock_0.tib, segments_2, _0.fdx, _0_MockRandom_0.pyl, _0.fdt]
[junit4:junit4] 2> 2558 T39 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[_1_NestedPulsing_0.tip, _1_Lucene41_0.doc, _0_Lucene41_0.pos, _1_MockFixedIntBlock_0.pyl, _0_MockFixedIntBlock_0.tib, _1.fnm, _1_MockRandom_0.pos, _0_NestedPulsing_0.pos, _0_MockFixedIntBlock_0.tii, _1_NestedPulsing_0.tim, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _0_NestedPulsing_0.doc, _1.nvm, _0.fnm, _1_MockFixedIntBlock_0.frq, _1_MockRandom_0.tip, _1.nvd, _1_NestedPulsing_0.pos, _0_MockFixedIntBlock_0.pos, _1_MockRandom_0.sd, _1_MockRandom_0.tim, _0_MockRandom_0.skp, _1.fdx, _1_Lucene41_0.pos, _0_MockRandom_0.frq, _1_MockFixedIntBlock_0.skp, _1.fdt, _0_Lucene41_0.doc, _0_MockRandom_0.doc, _0_MockRandom_0.pos, _1_MockRandom_0.doc, _1_MockFixedIntBlock_0.pos, _1_MockRandom_0.frq, _1_MockFixedIntBlock_0.doc, _0_NestedPulsing_0.tip, _0_NestedPulsing_0.tim, _1_NestedPulsing_0.doc, _0_MockFixedIntBlock_0.pyl, _0_MockFixedIntBlock_0.skp, _0.nvd, _0.si, _0_MockRandom_0.tib, _1_MockFixedIntBlock_0.tii, _1_Lucene41_0.tim, _1_Lucene41_0.tip, _1_MockRandom_0.skp, _0.nvm, _0_MockFixedIntBlock_0.frq, _0_MockRandom_0.sd, _1_MockRandom_0.pyl, _0_MockRandom_0.tiv, _0_MockFixedIntBlock_0.doc, _1.si, _1_MockFixedIntBlock_0.tib, segments_2, _0.fdx, _0_MockRandom_0.pyl, _0.fdt]
[junit4:junit4] 2> 2559 T36 oas.SolrTestCaseJ4.tearDown ###Ending testSoftAndHardCommitMaxTimeMixedAdds
[junit4:junit4] 2> 2562 T39 oass.SolrIndexSearcher.<init> Opening Searcher@5c68b20 main
[junit4:junit4] 2> 2563 T39 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 2565 T38 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@5c68b20 main{StandardDirectoryReader(segments_2:5:nrt _0(4.2.1):C1 _1(4.2.1):C1)}
[junit4:junit4] 2> NOTE: download the large Jenkins line-docs file by running 'ant get-jenkins-line-docs' in the lucene directory.
[junit4:junit4] 2> NOTE: reproduce with: ant test -Dtestcase=SoftAutoCommitTest -Dtests.method=testSoftAndHardCommitMaxTimeMixedAdds -Dtests.seed=80AB1224E117CA42 -Dtests.multiplier=2 -Dtests.nightly=true -Dtests.slow=true -Dtests.linedocsfile=/home/hudson/lucene-data/enwiki.random.lines.txt -Dtests.locale=fr_LU -Dtests.timezone=America/Manaus -Dtests.file.encoding=US-ASCII
[junit4:junit4] FAILURE 1.94s J1 | SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds <<<
[junit4:junit4] > Throwable #1: java.lang.AssertionError: searcher529 wasn't soon enough after soft529: 1363861548737 !< 1363861548492 + 228 (fudge)
[junit4:junit4] > at __randomizedtesting.SeedInfo.seed([80AB1224E117CA42:D17FEBA45064FAE5]: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.testSoftAndHardCommitMaxTimeMixedAdds(SoftAutoCommitTest.java:137)
[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:616)
[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:679)
[junit4:junit4] 2> 2655 T36 oas.SolrTestCaseJ4.setUp ###Starting testSoftAndHardCommitMaxTimeDelete
[junit4:junit4] 2> 2656 T36 oasc.CoreContainer.reload Reloading SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4] 2> 2656 T36 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4] 2> 2657 T36 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4] 2> 2657 T36 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 2706 T36 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 2754 T36 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 2754 T36 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 2759 T36 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 3181 T36 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 3190 T36 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 3193 T36 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 3206 T36 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 3210 T36 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 3213 T36 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 3213 T36 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 3214 T36 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 3214 T36 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 3215 T36 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 3215 T36 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 3215 T36 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J1/./solrtest-SoftAutoCommitTest-1363861546645/
[junit4:junit4] 2> 3216 T36 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@63f8247d
[junit4:junit4] 2> 3216 T36 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J1/./solrtest-SoftAutoCommitTest-1363861546645/index/
[junit4:junit4] 2> 3217 T36 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4] 2> 3219 T36 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 3219 T36 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4] 2> 3220 T36 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 3220 T36 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4] 2> 3221 T36 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 3221 T36 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 3221 T36 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 3222 T36 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 3223 T36 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 3223 T36 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4] 2> 3224 T36 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4] 2> 3224 T36 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 3225 T36 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 3225 T36 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 3226 T36 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 3226 T36 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 3227 T36 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 3228 T36 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 3228 T36 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 3229 T36 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 3229 T36 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 3230 T36 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 3231 T36 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 3231 T36 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 3232 T36 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4] 2> 3233 T36 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4] 2> 3237 T36 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 3241 T36 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4] 2> 3242 T36 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [THROW.ERROR.ON.ADD.UPDATEPROCESSOR.JS, SOLRCONFIG-HIGHLIGHT.XML, SCHEMA-REQUIRED-FIELDS.XML, TRIVIAL.UPDATEPROCESSOR1.JS, SCHEMA-MINIMAL.XML, BAD-SCHEMA-DUP-DYNAMICFIELD.XML, SCHEMA-REPLICATION2.XML, BAD-SCHEMA-DOCVALUES-NOT-REQUIRED-NO-DEFAULT.XML, SOLRCONFIG-CACHING.XML, SCHEMA-POSTINGSHIGHLIGHT.XML, SOLRCONFIG-REPEATER.XML, REGEX-BOOST-PROCESSOR-TEST.TXT, BAD-SCHEMA-NONTEXT-ANALYZER.XML, BAD-SCHEMA-CURRENCY-FT-BOGUS-CODE-IN-XML.XML, SOLRCONFIG-MERGEPOLICY.XML, CURRENCY.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-IB.XML, SCHEMA-CHARFILTERS.XML, SOLRCONFIG-QUERYSENDER.XML, SCHEMA-REPLICATION1.XML, SOLRCONFIG-SNIPPET-PROCESSOR.XML, DA_UTF8.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, SCHEMA-REVERSED.XML, STOPTYPES-2.TXT, BAD-SCHEMA-CURRENCY-FT-MULTIVALUED.XML, SOLRCONFIG-SPELLCHECKCOMPONENT.XML, SCHEMA-DFR.XML, BAD-SCHEMA-CURRENCY-MULTIVALUED.XML, SOLRCONFIG-PHRASESUGGEST.XML, BAD-SCHEMA-NOT-INDEXED-BUT-POS.XML, KEEP-1.TXT, SCHEMA-SPATIAL.XML, OPEN-EXCHANGE-RATES.JSON, STOPWITHBOM.TXT, SOLRCONFIG-SPELLCHECKER.XML, SOLRCONFIG-POSTINGSHIGHLIGHT.XML, SCHEMA-BINARYFIELD.XML, SOLRCONFIG-UPDATE-PROCESSOR-CHAINS.XML, BAD-SCHEMA-OMIT-TF-BUT-NOT-POS.XML, BAD-SCHEMA-DUP-FIELDTYPE.XML, SCHEMA-XINCLUDE.XML, SOLRCONFIG-MASTER1.XML, SCHEMA-BEHAVIOR.XML, SYNONYMS.TXT, 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, SOLRCONFIG-TERMINDEX.XML, SCHEMA-LMDIRICHLET.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-DELPOLICY1.XML, SOLRCONFIG-SLAVE1.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-QUERYSENDER-NOQUERY.XML, SOLRCONFIG-ALTDIRECTORY.XML, COMPOUNDDICTIONARY.TXT, BAD-SCHEMA-CURRENCY-FT-BOGUS-DEFAULT-CODE.XML, BAD-CURRENCY.XML, SOLRCONFIG_PERF.XML, SOLRCONFIG-INDEXCONFIG.XML, SCHEMA-NOT-REQUIRED-UNIQUE-KEY.XML, BAD-SCHEMA-ANALYZER-CLASS-AND-NESTED.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> 3245 T36 oass.SolrIndexSearcher.<init> Opening Searcher@53d26552 main
[junit4:junit4] 2> 3246 T36 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 3246 T36 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 3246 T36 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4] 2> 3248 T36 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4] 2> 3261 T41 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@53d26552 main{StandardDirectoryReader(segments_2:5:nrt _0(4.2.1):C1 _1(4.2.1):C1)}
[junit4:junit4] 2> 3267 T36 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 3268 T36 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 3268 T36 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4:junit4] 2> 3273 T36 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@2207d8bb lockFactory=org.apache.lucene.store.NativeFSLockFactory@45a8123b)),segFN=segments_2,generation=2,filenames=[_1_NestedPulsing_0.tip, _1_Lucene41_0.doc, _0_Lucene41_0.pos, _1_MockFixedIntBlock_0.pyl, _0_MockFixedIntBlock_0.tib, _1_MockRandom_0.pos, _1.fnm, _0_NestedPulsing_0.pos, _0_MockFixedIntBlock_0.tii, _1_NestedPulsing_0.tim, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _0_NestedPulsing_0.doc, _1.nvm, _0.fnm, _1_MockFixedIntBlock_0.frq, _1_MockRandom_0.tip, _1.nvd, _1_NestedPulsing_0.pos, _0_MockFixedIntBlock_0.pos, _1_MockRandom_0.sd, _1_MockRandom_0.tim, _0_MockRandom_0.skp, _1.fdx, _1_Lucene41_0.pos, _0_MockRandom_0.frq, _1_MockFixedIntBlock_0.skp, _1.fdt, _0_Lucene41_0.doc, _0_MockRandom_0.doc, _0_MockRandom_0.pos, _1_MockRandom_0.doc, _1_MockFixedIntBlock_0.pos, _1_MockRandom_0.frq, _1_MockFixedIntBlock_0.doc, _0_NestedPulsing_0.tip, _0_NestedPulsing_0.tim, _1_NestedPulsing_0.doc, _0_MockFixedIntBlock_0.skp, _0_MockFixedIntBlock_0.pyl, _0.nvd, _0.si, _0_MockRandom_0.tib, _1_MockFixedIntBlock_0.tii, _1_Lucene41_0.tim, _1_Lucene41_0.tip, _1_MockRandom_0.skp, _0.nvm, _0_MockFixedIntBlock_0.frq, _0_MockRandom_0.sd, _1_MockRandom_0.pyl, _0_MockRandom_0.tiv, _0_MockFixedIntBlock_0.doc, _1.si, _1_MockFixedIntBlock_0.tib, segments_2, _0.fdx, _0_MockRandom_0.pyl, _0.fdt]
[junit4:junit4] 2> 3274 T36 oasc.SolrDeletionPolicy.updateCommits newest commit = 2[_1_NestedPulsing_0.tip, _1_Lucene41_0.doc, _0_Lucene41_0.pos, _1_MockFixedIntBlock_0.pyl, _0_MockFixedIntBlock_0.tib, _1_MockRandom_0.pos, _1.fnm, _0_NestedPulsing_0.pos, _0_MockFixedIntBlock_0.tii, _1_NestedPulsing_0.tim, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _0_NestedPulsing_0.doc, _1.nvm, _0.fnm, _1_MockFixedIntBlock_0.frq, _1_MockRandom_0.tip, _1.nvd, _1_NestedPulsing_0.pos, _0_MockFixedIntBlock_0.pos, _1_MockRandom_0.sd, _1_MockRandom_0.tim, _0_MockRandom_0.skp, _1.fdx, _1_Lucene41_0.pos, _0_MockRandom_0.frq, _1_MockFixedIntBlock_0.skp, _1.fdt, _0_Lucene41_0.doc, _0_MockRandom_0.doc, _0_MockRandom_0.pos, _1_MockRandom_0.doc, _1_MockFixedIntBlock_0.pos, _1_MockRandom_0.frq, _1_MockFixedIntBlock_0.doc, _0_NestedPulsing_0.tip, _0_NestedPulsing_0.tim, _1_NestedPulsing_0.doc, _0_MockFixedIntBlock_0.skp, _0_MockFixedIntBlock_0.pyl, _0.nvd, _0.si, _0_MockRandom_0.tib, _1_MockFixedIntBlock_0.tii, _1_Lucene41_0.tim, _1_Lucene41_0.tip, _1_MockRandom_0.skp, _0.nvm, _0_MockFixedIntBlock_0.frq, _0_MockRandom_0.sd, _1_MockRandom_0.pyl, _0_MockRandom_0.tiv, _0_MockFixedIntBlock_0.doc, _1.si, _1_MockFixedIntBlock_0.tib, segments_2, _0.fdx, _0_MockRandom_0.pyl, _0.fdt]
[junit4:junit4] 2> 3275 T36 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 3279 T36 oass.SolrIndexSearcher.<init> Opening Searcher@7366c3a0 main
[junit4:junit4] 2> 3280 T36 oasc.CoreContainer.registerCore replacing core: collection1
[junit4:junit4] 2> 3280 T36 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@49af7e68
[junit4:junit4] 2> 3281 T41 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7366c3a0 main{StandardDirectoryReader(segments_2:5:nrt _0(4.2.1):C1 _1(4.2.1):C1)}
[junit4:junit4] 2> 3287 T36 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=2,autocommit maxTime=1200ms,autocommits=1,soft autocommit maxTime=500ms,soft autocommits=1,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> 3287 T36 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> ASYNC NEW_CORE C8 name=collection1 org.apache.solr.core.SolrCore@459bdb65
[junit4:junit4] 2> 3297 T36 C8 UPDATE [collection1] webapp=null path=null params={} {add=[529]} 0 3
[junit4:junit4] 2> 3303 T36 C8 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 3314 T36 C8 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@2207d8bb lockFactory=org.apache.lucene.store.NativeFSLockFactory@45a8123b)),segFN=segments_2,generation=2,filenames=[_1_NestedPulsing_0.tip, _1_Lucene41_0.doc, _0_Lucene41_0.pos, _1_MockFixedIntBlock_0.pyl, _0_MockFixedIntBlock_0.tib, _1_MockRandom_0.pos, _1.fnm, _0_NestedPulsing_0.pos, _0_MockFixedIntBlock_0.tii, _1_NestedPulsing_0.tim, _0_Lucene41_0.tim, _0_Lucene41_0.tip, _0_NestedPulsing_0.doc, _1.nvm, _0.fnm, _1_MockFixedIntBlock_0.frq, _1_MockRandom_0.tip, _1.nvd, _1_NestedPulsing_0.pos, _0_MockFixedIntBlock_0.pos, _1_MockRandom_0.sd, _1_MockRandom_0.tim, _0_MockRandom_0.skp, _1.fdx, _1_Lucene41_0.pos, _0_MockRandom_0.frq, _1_MockFixedIntBlock_0.skp, _1.fdt, _0_Lucene41_0.doc, _0_MockRandom_0.doc, _0_MockRandom_0.pos, _1_MockRandom_0.doc, _1_MockFixedIntBlock_0.pos, _1_MockRandom_0.frq, _1_MockFixedIntBlock_0.doc, _0_NestedPulsing_0.tip, _0_NestedPulsing_0.tim, _1_NestedPulsing_0.doc, _0_MockFixedIntBlock_0.skp, _0_MockFixedIntBlock_0.pyl, _0.nvd, _0.si, _0_MockRandom_0.tib, _1_MockFixedIntBlock_0.tii, _1_Lucene41_0.tim, _1_Lucene41_0.tip, _1_MockRandom_0.skp, _0.nvm, _0_MockFixedIntBlock_0.frq, _0_MockRandom_0.sd, _1_MockRandom_0.pyl, _0_MockRandom_0.tiv, _0_MockFixedIntBlock_0.doc, _1.si, _1_MockFixedIntBlock_0.tib, segments_2, _0.fdx, _0_MockRandom_0.pyl, _0.fdt]
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@2207d8bb lockFactory=org.apache.lucene.store.NativeFSLockFactory@45a8123b)),segFN=segments_3,generation=3,filenames=[_1_NestedPulsing_0.tip, _2_NestedPulsing_0.tim, _2_Lucene41_0.pos, _1_Lucene41_0.doc, _2_Lucene41_0.tim, _1_MockFixedIntBlock_0.pyl, _2_Lucene41_0.tip, _1_MockRandom_0.pos, _1.fnm, _2_MockFixedIntBlock_0.tii, _2_MockFixedIntBlock_0.tib, _2_MockFixedIntBlock_0.pyl, _2_MockFixedIntBlock_0.frq, _1_NestedPulsing_0.tim, _2_NestedPulsing_0.tip, _1.nvm, _1_MockFixedIntBlock_0.frq, _1_MockRandom_0.tip, _1.nvd, _1_NestedPulsing_0.pos, _2.fdt, _1_MockRandom_0.tim, _1_MockRandom_0.sd, _2_Lucene41_0.doc, _2.fdx, _1.fdx, _1_Lucene41_0.pos, _2.nvm, _1_MockFixedIntBlock_0.skp, _2_MockFixedIntBlock_0.pos, _1.fdt, _2_NestedPulsing_0.pos, _2.nvd, _2_MockFixedIntBlock_0.doc, _1_MockRandom_0.doc, _1_MockFixedIntBlock_0.pos, _1_MockRandom_0.frq, _2.si, _2_MockRandom_0.tip, _1_MockFixedIntBlock_0.doc, _2_MockRandom_0.tim, _2_MockFixedIntBlock_0.skp, _1_NestedPulsing_0.doc, _2_MockRandom_0.pyl, _2_MockRandom_0.pos, _1_MockFixedIntBlock_0.tii, _1_Lucene41_0.tim, _1_Lucene41_0.tip, _1_MockRandom_0.skp, _2.fnm, _2_MockRandom_0.sd, _1_MockRandom_0.pyl, _2_MockRandom_0.skp, _1.si, _2_MockRandom_0.frq, _1_MockFixedIntBlock_0.tib, _2_MockRandom_0.doc, segments_3, _2_NestedPulsing_0.doc]
[junit4:junit4] 2> 3315 T36 C8 oasc.SolrDeletionPolicy.updateCommits newest commit = 3[_1_NestedPulsing_0.tip, _2_NestedPulsing_0.tim, _2_Lucene41_0.pos, _1_Lucene41_0.doc, _2_Lucene41_0.tim, _1_MockFixedIntBlock_0.pyl, _2_Lucene41_0.tip, _1_MockRandom_0.pos, _1.fnm, _2_MockFixedIntBlock_0.tii, _2_MockFixedIntBlock_0.tib, _2_MockFixedIntBlock_0.pyl, _2_MockFixedIntBlock_0.frq, _1_NestedPulsing_0.tim, _2_NestedPulsing_0.tip, _1.nvm, _1_MockFixedIntBlock_0.frq, _1_MockRandom_0.tip, _1.nvd, _1_NestedPulsing_0.pos, _2.fdt, _1_MockRandom_0.tim, _1_MockRandom_0.sd, _2_Lucene41_0.doc, _2.fdx, _1.fdx, _1_Lucene41_0.pos, _2.nvm, _1_MockFixedIntBlock_0.skp, _2_MockFixedIntBlock_0.pos, _1.fdt, _2_NestedPulsing_0.pos, _2.nvd, _2_MockFixedIntBlock_0.doc, _1_MockRandom_0.doc, _1_MockFixedIntBlock_0.pos, _1_MockRandom_0.frq, _2.si, _2_MockRandom_0.tip, _1_MockFixedIntBlock_0.doc, _2_MockRandom_0.tim, _2_MockFixedIntBlock_0.skp, _1_NestedPulsing_0.doc, _2_MockRandom_0.pyl, _2_MockRandom_0.pos, _1_MockFixedIntBlock_0.tii, _1_Lucene41_0.tim, _1_Lucene41_0.tip, _1_MockRandom_0.skp, _2.fnm, _2_MockRandom_0.sd, _1_MockRandom_0.pyl, _2_MockRandom_0.skp, _1.si, _2_MockRandom_0.frq, _1_MockFixedIntBlock_0.tib, _2_MockRandom_0.doc, segments_3, _2_NestedPulsing_0.doc]
[junit4:junit4] 2> 3319 T36 C8 oass.SolrIndexSearcher.<init> Opening Searcher@3d0bc85 main
[junit4:junit4] 2> 3319 T36 C8 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 3321 T41 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3d0bc85 main{StandardDirectoryReader(segments_3:9:nrt _1(4.2.1):C1 _2(4.2.1):C1)}
[junit4:junit4] 2> 3321 T36 C8 UPDATE [collection1] webapp=null path=null params={} {commit=} 0 18
[junit4:junit4] 2> 3328 T36 C8 UPDATE [collection1] webapp=null path=null params={} {delete=[529]} 0 1
[junit4:junit4] 2> 3830 T43 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4:junit4] 2> 3833 T43 oass.SolrIndexSearcher.<init> Opening Searcher@47fbad7 main
[junit4:junit4] 2> 3833 T43 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 3836 T41 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@47fbad7 main{StandardDirectoryReader(segments_3:11:nrt _1(4.2.1):C1)}
[junit4:junit4] 2> 3842 T36 C8 UPDATE [collection1] webapp=null path=null params={} {add=[550]} 0 2
[junit4:junit4] 2> 4343 T43 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4:junit4] 2> 4355 T43 oass.SolrIndexSearcher.<init> Opening Searcher@35e5ebbf main
[junit4:junit4] 2> 4355 T43 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 4358 T41 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@35e5ebbf main{StandardDirectoryReader(segments_3:13:nrt _1(4.2.1):C1 _3(4.2.1):C1)}
[junit4:junit4] 2> 4530 T42 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 4547 T42 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@2207d8bb lockFactory=org.apache.lucene.store.NativeFSLockFactory@45a8123b)),segFN=segments_3,generation=3,filenames=[_1_NestedPulsing_0.tip, _2_NestedPulsing_0.tim, _2_Lucene41_0.pos, _1_Lucene41_0.doc, _2_Lucene41_0.tim, _1_MockFixedIntBlock_0.pyl, _2_Lucene41_0.tip, _1_MockRandom_0.pos, _1.fnm, _2_MockFixedIntBlock_0.tii, _2_MockFixedIntBlock_0.tib, _2_MockFixedIntBlock_0.pyl, _2_MockFixedIntBlock_0.frq, _1_NestedPulsing_0.tim, _2_NestedPulsing_0.tip, _1.nvm, _1_MockFixedIntBlock_0.frq, _1_MockRandom_0.tip, _1.nvd, _1_NestedPulsing_0.pos, _2.fdt, _1_MockRandom_0.tim, _1_MockRandom_0.sd, _2_Lucene41_0.doc, _2.fdx, _1.fdx, _1_Lucene41_0.pos, _2.nvm, _1_MockFixedIntBlock_0.skp, _2_MockFixedIntBlock_0.pos, _1.fdt, _2_NestedPulsing_0.pos, _2.nvd, _2_MockFixedIntBlock_0.doc, _1_MockRandom_0.doc, _1_MockFixedIntBlock_0.pos, _1_MockRandom_0.frq, _2.si, _2_MockRandom_0.tip, _1_MockFixedIntBlock_0.doc, _2_MockRandom_0.tim, _2_MockFixedIntBlock_0.skp, _1_NestedPulsing_0.doc, _2_MockRandom_0.pyl, _2_MockRandom_0.pos, _1_MockFixedIntBlock_0.tii, _1_Lucene41_0.tim, _1_Lucene41_0.tip, _1_MockRandom_0.skp, _2.fnm, _2_MockRandom_0.sd, _1_MockRandom_0.pyl, _2_MockRandom_0.skp, _1.si, _2_MockRandom_0.frq, _1_MockFixedIntBlock_0.tib, _2_MockRandom_0.doc, segments_3, _2_NestedPulsing_0.doc]
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@2207d8bb lockFactory=org.apache.lucene.store.NativeFSLockFactory@45a8123b)),segFN=segments_4,generation=4,filenames=[_1_NestedPulsing_0.tip, _1_Lucene41_0.doc, _3_MockFixedIntBlock_0.skp, _1_MockFixedIntBlock_0.pyl, _3.fdt, _1_MockRandom_0.pos, _1.fnm, _3.nvd, _3_MockFixedIntBlock_0.pyl, _3_Lucene41_0.pos, _3_MockRandom_0.skp, _3.nvm, _1_NestedPulsing_0.tim, _1.nvm, _1_MockFixedIntBlock_0.frq, _1_MockRandom_0.tip, _1.nvd, _1_NestedPulsing_0.pos, _3_NestedPulsing_0.tim, _1_MockRandom_0.tim, _1_MockRandom_0.sd, _3_MockRandom_0.tib, _1.fdx, _1_Lucene41_0.pos, _3_Lucene41_0.doc, _1_MockFixedIntBlock_0.skp, _3_NestedPulsing_0.tip, _1.fdt, _3_MockRandom_0.tiv, _3.si, _1_MockRandom_0.doc, _1_MockFixedIntBlock_0.pos, _1_MockRandom_0.frq, _3_MockFixedIntBlock_0.frq, _1_MockFixedIntBlock_0.doc, _3_MockRandom_0.doc, _3_MockFixedIntBlock_0.doc, _3_MockRandom_0.frq, _3.fnm, _1_NestedPulsing_0.doc, _3_Lucene41_0.tip, _3_Lucene41_0.tim, _1_MockFixedIntBlock_0.tii, _3_NestedPulsing_0.pos, _1_Lucene41_0.tim, _3_MockFixedIntBlock_0.tib, _1_Lucene41_0.tip, _1_MockRandom_0.skp, _3_MockFixedIntBlock_0.pos, _3_MockRandom_0.sd, _3.fdx, _3_NestedPulsing_0.doc, _1_MockRandom_0.pyl, _1.si, _3_MockRandom_0.pyl, _1_MockFixedIntBlock_0.tib, _3_MockRandom_0.pos, _3_MockFixedIntBlock_0.tii, segments_4]
[junit4:junit4] 2> 4548 T42 oasc.SolrDeletionPolicy.updateCommits newest commit = 4[_1_NestedPulsing_0.tip, _1_Lucene41_0.doc, _3_MockFixedIntBlock_0.skp, _1_MockFixedIntBlock_0.pyl, _3.fdt, _1_MockRandom_0.pos, _1.fnm, _3.nvd, _3_MockFixedIntBlock_0.pyl, _3_Lucene41_0.pos, _3_MockRandom_0.skp, _3.nvm, _1_NestedPulsing_0.tim, _1.nvm, _1_MockFixedIntBlock_0.frq, _1_MockRandom_0.tip, _1.nvd, _1_NestedPulsing_0.pos, _3_NestedPulsing_0.tim, _1_MockRandom_0.tim, _1_MockRandom_0.sd, _3_MockRandom_0.tib, _1.fdx, _1_Lucene41_0.pos, _3_Lucene41_0.doc, _1_MockFixedIntBlock_0.skp, _3_NestedPulsing_0.tip, _1.fdt, _3_MockRandom_0.tiv, _3.si, _1_MockRandom_0.doc, _1_MockFixedIntBlock_0.pos, _1_MockRandom_0.frq, _3_MockFixedIntBlock_0.frq, _1_MockFixedIntBlock_0.doc, _3_MockRandom_0.doc, _3_MockFixedIntBlock_0.doc, _3_MockRandom_0.frq, _3.fnm, _1_NestedPulsing_0.doc, _3_Lucene41_0.tip, _3_Lucene41_0.tim, _1_MockFixedIntBlock_0.tii, _3_NestedPulsing_0.pos, _1_Lucene41_0.tim, _3_MockFixedIntBlock_0.tib, _1_Lucene41_0.tip, _1_MockRandom_0.skp, _3_MockFixedIntBlock_0.pos, _3_MockRandom_0.sd, _3.fdx, _3_NestedPulsing_0.doc, _1_MockRandom_0.pyl, _1.si, _3_MockRandom_0.pyl, _1_MockFixedIntBlock_0.tib, _3_MockRandom_0.pos, _3_MockFixedIntBlock_0.tii, segments_4]
[junit4:junit4] 2> 4549 T42 oass.SolrIndexSearcher.<init> Opening Searcher@3fdb8a73 main
[junit4:junit4] 2> 4549 T42 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 4551 T41 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3fdb8a73 main{StandardDirectoryReader(segments_3:13:nrt _1(4.2.1):C1 _3(4.2.1):C1)}
[junit4:junit4] 2> 6550 T36 oas.SolrTestCaseJ4.tearDown ###Ending testSoftAndHardCommitMaxTimeDelete
[junit4:junit4] 2> 6555 T36 oas.SolrTestCaseJ4.setUp ###Starting testSoftAndHardCommitMaxTimeRapidAdds
[junit4:junit4] 2> 6555 T36 oasc.CoreContainer.reload Reloading SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1
[junit4:junit4] 2> 6555 T36 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1/'
[junit4:junit4] 2> 6556 T36 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1/lib/README' to classloader
[junit4:junit4] 2> 6557 T36 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 6607 T36 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 6656 T36 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 6657 T36 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 6661 T36 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 7235 T36 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 7248 T36 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 7252 T36 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 7271 T36 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 7276 T36 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 7281 T36 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 7282 T36 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 7282 T36 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 7283 T36 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 7284 T36 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 7284 T36 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 7285 T36 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1/, dataDir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J1/./solrtest-SoftAutoCommitTest-1363861546645/
[junit4:junit4] 2> 7286 T36 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@63f8247d
[junit4:junit4] 2> 7287 T36 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J1/./solrtest-SoftAutoCommitTest-1363861546645/index/
[junit4:junit4] 2> 7287 T36 oasc.SolrCore.initWriters created xml: solr.XMLResponseWriter
[junit4:junit4] 2> 7290 T36 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 7290 T36 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4:junit4] 2> 7291 T36 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 7292 T36 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4:junit4] 2> 7293 T36 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 7293 T36 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 7294 T36 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 7295 T36 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 7296 T36 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 7297 T36 oasc.RequestHandlers.initHandlersFromConfig created dismax: solr.SearchHandler
[junit4:junit4] 2> 7297 T36 oasc.RequestHandlers.initHandlersFromConfig created mock: org.apache.solr.core.MockQuerySenderListenerReqHandler
[junit4:junit4] 2> 7298 T36 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 7299 T36 oasc.RequestHandlers.initHandlersFromConfig created defaults: solr.StandardRequestHandler
[junit4:junit4] 2> 7299 T36 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.StandardRequestHandler
[junit4:junit4] 2> 7300 T36 oasc.RequestHandlers.initHandlersFromConfig created lazy: solr.StandardRequestHandler
[junit4:junit4] 2> 7301 T36 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 7302 T36 oasc.RequestHandlers.initHandlersFromConfig created /terms: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 7303 T36 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 7304 T36 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 7305 T36 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 7306 T36 oasc.RequestHandlers.initHandlersFromConfig created spellCheckWithWordbreak_Direct: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 7307 T36 oasc.RequestHandlers.initHandlersFromConfig created spellCheckCompRH1: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 7307 T36 oasc.RequestHandlers.initHandlersFromConfig created mltrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 7308 T36 oasc.RequestHandlers.initHandlersFromConfig created tvrh: org.apache.solr.handler.component.SearchHandler
[junit4:junit4] 2> 7309 T36 oasc.RequestHandlers.initHandlersFromConfig created /mlt: solr.MoreLikeThisHandler
[junit4:junit4] 2> 7310 T36 oasc.RequestHandlers.initHandlersFromConfig created /debug/dump: solr.DumpRequestHandler
[junit4:junit4] 2> 7318 T36 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 7320 T36 oasc.SolrCore.initDeprecatedSupport WARNING solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4:junit4] 2> 7323 T36 oasc.SolrCore.initDeprecatedSupport WARNING adding ShowFileRequestHandler with hidden files: [THROW.ERROR.ON.ADD.UPDATEPROCESSOR.JS, SOLRCONFIG-HIGHLIGHT.XML, SCHEMA-REQUIRED-FIELDS.XML, TRIVIAL.UPDATEPROCESSOR1.JS, SCHEMA-MINIMAL.XML, BAD-SCHEMA-DUP-DYNAMICFIELD.XML, SCHEMA-REPLICATION2.XML, BAD-SCHEMA-DOCVALUES-NOT-REQUIRED-NO-DEFAULT.XML, SOLRCONFIG-CACHING.XML, SCHEMA-POSTINGSHIGHLIGHT.XML, SOLRCONFIG-REPEATER.XML, REGEX-BOOST-PROCESSOR-TEST.TXT, BAD-SCHEMA-NONTEXT-ANALYZER.XML, BAD-SCHEMA-CURRENCY-FT-BOGUS-CODE-IN-XML.XML, SOLRCONFIG-MERGEPOLICY.XML, CURRENCY.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-IB.XML, SCHEMA-CHARFILTERS.XML, SOLRCONFIG-QUERYSENDER.XML, SCHEMA-REPLICATION1.XML, SOLRCONFIG-SNIPPET-PROCESSOR.XML, DA_UTF8.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, SCHEMA-REVERSED.XML, STOPTYPES-2.TXT, BAD-SCHEMA-CURRENCY-FT-MULTIVALUED.XML, SOLRCONFIG-SPELLCHECKCOMPONENT.XML, SCHEMA-DFR.XML, BAD-SCHEMA-CURRENCY-MULTIVALUED.XML, SOLRCONFIG-PHRASESUGGEST.XML, BAD-SCHEMA-NOT-INDEXED-BUT-POS.XML, KEEP-1.TXT, SCHEMA-SPATIAL.XML, OPEN-EXCHANGE-RATES.JSON, STOPWITHBOM.TXT, SOLRCONFIG-SPELLCHECKER.XML, SOLRCONFIG-POSTINGSHIGHLIGHT.XML, SCHEMA-BINARYFIELD.XML, SOLRCONFIG-UPDATE-PROCESSOR-CHAINS.XML, BAD-SCHEMA-OMIT-TF-BUT-NOT-POS.XML, BAD-SCHEMA-DUP-FIELDTYPE.XML, SCHEMA-XINCLUDE.XML, SOLRCONFIG-MASTER1.XML, SCHEMA-BEHAVIOR.XML, SYNONYMS.TXT, 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, SOLRCONFIG-TERMINDEX.XML, SCHEMA-LMDIRICHLET.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-DELPOLICY1.XML, SOLRCONFIG-SLAVE1.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-QUERYSENDER-NOQUERY.XML, SOLRCONFIG-ALTDIRECTORY.XML, COMPOUNDDICTIONARY.TXT, BAD-SCHEMA-CURRENCY-FT-BOGUS-DEFAULT-CODE.XML, BAD-CURRENCY.XML, SOLRCONFIG_PERF.XML, SOLRCONFIG-INDEXCONFIG.XML, SCHEMA-NOT-REQUIRED-UNIQUE-KEY.XML, BAD-SCHEMA-ANALYZER-CLASS-AND-NESTED.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> 7326 T36 oass.SolrIndexSearcher.<init> Opening Searcher@e3f6d main
[junit4:junit4] 2> 7327 T36 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 7328 T36 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 7328 T36 oashc.SpellCheckComponent.inform Initializing spell checkers
[junit4:junit4] 2> 7331 T36 oass.DirectSolrSpellChecker.init init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4:junit4] 2> 7352 T44 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@e3f6d main{StandardDirectoryReader(segments_4:13:nrt _1(4.2.1):C1 _3(4.2.1):C1)}
[junit4:junit4] 2> 7362 T36 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 7362 T36 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 7362 T36 oasu.DefaultSolrCoreState.newIndexWriter Closing old IndexWriter... core=collection1
[junit4:junit4] 2> 7370 T36 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits:num=1
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@2207d8bb lockFactory=org.apache.lucene.store.NativeFSLockFactory@45a8123b)),segFN=segments_4,generation=4,filenames=[_1_NestedPulsing_0.tip, _1_Lucene41_0.doc, _3_MockFixedIntBlock_0.skp, _1_MockFixedIntBlock_0.pyl, _3.fdt, _1_MockRandom_0.pos, _1.fnm, _3_MockFixedIntBlock_0.pyl, _3.nvd, _3_Lucene41_0.pos, _3_MockRandom_0.skp, _3.nvm, _1_NestedPulsing_0.tim, _1.nvm, _1_MockFixedIntBlock_0.frq, _1_MockRandom_0.tip, _1.nvd, _1_NestedPulsing_0.pos, _3_NestedPulsing_0.tim, _1_MockRandom_0.tim, _1_MockRandom_0.sd, _3_MockRandom_0.tib, _1.fdx, _1_Lucene41_0.pos, _3_Lucene41_0.doc, _1_MockFixedIntBlock_0.skp, _3_NestedPulsing_0.tip, _1.fdt, _3_MockRandom_0.tiv, _3.si, _1_MockRandom_0.doc, _1_MockFixedIntBlock_0.pos, _1_MockRandom_0.frq, _3_MockFixedIntBlock_0.frq, _1_MockFixedIntBlock_0.doc, _3_MockRandom_0.doc, _3_MockFixedIntBlock_0.doc, _3_MockRandom_0.frq, _3.fnm, _1_NestedPulsing_0.doc, _3_Lucene41_0.tip, _3_Lucene41_0.tim, _1_MockFixedIntBlock_0.tii, _3_NestedPulsing_0.pos, _1_Lucene41_0.tim, _3_MockFixedIntBlock_0.tib, _1_Lucene41_0.tip, _1_MockRandom_0.skp, _3_MockFixedIntBlock_0.pos, _3_MockRandom_0.sd, _3.fdx, _3_NestedPulsing_0.doc, _1_MockRandom_0.pyl, _1.si, _3_MockRandom_0.pyl, _1_MockFixedIntBlock_0.tib, _3_MockRandom_0.pos, _3_MockFixedIntBlock_0.tii, segments_4]
[junit4:junit4] 2> 7370 T36 oasc.SolrDeletionPolicy.updateCommits newest commit = 4[_1_NestedPulsing_0.tip, _1_Lucene41_0.doc, _3_MockFixedIntBlock_0.skp, _1_MockFixedIntBlock_0.pyl, _3.fdt, _1_MockRandom_0.pos, _1.fnm, _3_MockFixedIntBlock_0.pyl, _3.nvd, _3_Lucene41_0.pos, _3_MockRandom_0.skp, _3.nvm, _1_NestedPulsing_0.tim, _1.nvm, _1_MockFixedIntBlock_0.frq, _1_MockRandom_0.tip, _1.nvd, _1_NestedPulsing_0.pos, _3_NestedPulsing_0.tim, _1_MockRandom_0.tim, _1_MockRandom_0.sd, _3_MockRandom_0.tib, _1.fdx, _1_Lucene41_0.pos, _3_Lucene41_0.doc, _1_MockFixedIntBlock_0.skp, _3_NestedPulsing_0.tip, _1.fdt, _3_MockRandom_0.tiv, _3.si, _1_MockRandom_0.doc, _1_MockFixedIntBlock_0.pos, _1_MockRandom_0.frq, _3_MockFixedIntBlock_0.frq, _1_MockFixedIntBlock_0.doc, _3_MockRandom_0.doc, _3_MockFixedIntBlock_0.doc, _3_MockRandom_0.frq, _3.fnm, _1_NestedPulsing_0.doc, _3_Lucene41_0.tip, _3_Lucene41_0.tim, _1_MockFixedIntBlock_0.tii, _3_NestedPulsing_0.pos, _1_Lucene41_0.tim, _3_MockFixedIntBlock_0.tib, _1_Lucene41_0.tip, _1_MockRandom_0.skp, _3_MockFixedIntBlock_0.pos, _3_MockRandom_0.sd, _3.fdx, _3_NestedPulsing_0.doc, _1_MockRandom_0.pyl, _1.si, _3_MockRandom_0.pyl, _1_MockFixedIntBlock_0.tib, _3_MockRandom_0.pos, _3_MockFixedIntBlock_0.tii, segments_4]
[junit4:junit4] 2> 7371 T36 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 7378 T36 oass.SolrIndexSearcher.<init> Opening Searcher@4f3ad88b main
[junit4:junit4] 2> 7378 T36 oasc.CoreContainer.registerCore replacing core: collection1
[junit4:junit4] 2> 7379 T36 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@459bdb65
[junit4:junit4] 2> 7380 T44 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4f3ad88b main{StandardDirectoryReader(segments_4:13:nrt _1(4.2.1):C1 _3(4.2.1):C1)}
[junit4:junit4] 2> 7388 T36 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> 7388 T36 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> ASYNC NEW_CORE C9 name=collection1 org.apache.solr.core.SolrCore@645064f
[junit4:junit4] 2> 7403 T36 C9 UPDATE [collection1] webapp=null path=null params={} {add=[5000]} 0 3
[junit4:junit4] 2> 7415 T36 C9 UPDATE [collection1] webapp=null path=null params={} {add=[5001]} 0 2
[junit4:junit4] 2> 7425 T36 C9 UPDATE [collection1] webapp=null path=null params={} {add=[5002]} 0 1
[junit4:junit4] 2> 7436 T36 C9 UPDATE [collection1] webapp=null path=null params={} {add=[5003]} 0 2
[junit4:junit4] 2> 7446 T36 C9 UPDATE [collection1] webapp=null path=null params={} {add=[5004]} 0 1
[junit4:junit4] 2> 7448 T36 oas.SolrTestCaseJ4.tearDown ###Ending testSoftAndHardCommitMaxTimeRapidAdds
[junit4:junit4] 2> 7451 T36 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4:junit4] 2> 7451 T36 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=2083573092
[junit4:junit4] 2> 7451 T36 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@645064f
[junit4:junit4] 2> 7466 T36 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> 7467 T36 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 7467 T36 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 7468 T36 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 7477 T36 C9 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=2
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@2207d8bb lockFactory=org.apache.lucene.store.NativeFSLockFactory@45a8123b)),segFN=segments_4,generation=4,filenames=[_1_NestedPulsing_0.tip, _1_Lucene41_0.doc, _3_MockFixedIntBlock_0.skp, _1_MockFixedIntBlock_0.pyl, _3.fdt, _1_MockRandom_0.pos, _1.fnm, _3_MockFixedIntBlock_0.pyl, _3.nvd, _3_Lucene41_0.pos, _3_MockRandom_0.skp, _3.nvm, _1_NestedPulsing_0.tim, _1.nvm, _1_MockFixedIntBlock_0.frq, _1_MockRandom_0.tip, _1.nvd, _1_NestedPulsing_0.pos, _3_NestedPulsing_0.tim, _1_MockRandom_0.tim, _1_MockRandom_0.sd, _3_MockRandom_0.tib, _1.fdx, _1_Lucene41_0.pos, _3_Lucene41_0.doc, _1_MockFixedIntBlock_0.skp, _3_NestedPulsing_0.tip, _1.fdt, _3_MockRandom_0.tiv, _3.si, _1_MockRandom_0.doc, _1_MockFixedIntBlock_0.pos, _1_MockRandom_0.frq, _3_MockFixedIntBlock_0.frq, _1_MockFixedIntBlock_0.doc, _3_MockRandom_0.doc, _3_MockFixedIntBlock_0.doc, _3_MockRandom_0.frq, _3.fnm, _1_NestedPulsing_0.doc, _3_Lucene41_0.tip, _3_Lucene41_0.tim, _1_MockFixedIntBlock_0.tii, _3_NestedPulsing_0.pos, _1_Lucene41_0.tim, _3_MockFixedIntBlock_0.tib, _1_Lucene41_0.tip, _1_MockRandom_0.skp, _3_MockFixedIntBlock_0.pos, _3_MockRandom_0.sd, _3.fdx, _3_NestedPulsing_0.doc, _1_MockRandom_0.pyl, _1.si, _3_MockRandom_0.pyl, _1_MockFixedIntBlock_0.tib, _3_MockRandom_0.pos, _3_MockFixedIntBlock_0.tii, segments_4]
[junit4:junit4] 2> commit{dir=RateLimitedDirectoryWrapper(MockDirWrapper(org.apache.lucene.store.RAMDirectory@2207d8bb lockFactory=org.apache.lucene.store.NativeFSLockFactory@45a8123b)),segFN=segments_5,generation=5,filenames=[_4_MockRandom_0.pos, _1_NestedPulsing_0.tip, _1_Lucene41_0.doc, _4_MockRandom_0.tii, _4_MockFixedIntBlock_0.tib, _3_MockFixedIntBlock_0.skp, _4_NestedPulsing_0.doc, _4_Lucene41_0.doc, _1_MockFixedIntBlock_0.pyl, _4.fnm, _4_MockRandom_0.tib, _3.fdt, _1_MockRandom_0.pos, _1.fnm, _4.fdx, _4_MockRandom_0.doc, _3_MockFixedIntBlock_0.pyl, _3.nvd, _3_Lucene41_0.pos, _4_MockFixedIntBlock_0.tii, _3_MockRandom_0.skp, _4_MockRandom_0.pyl, _4_Lucene41_0.pos, _3.nvm, _1_NestedPulsing_0.tim, _1.nvm, _4_MockFixedIntBlock_0.pos, _1_MockFixedIntBlock_0.frq, _4_MockFixedIntBlock_0.skp, _1_MockRandom_0.tip, _1.nvd, _1_NestedPulsing_0.pos, _3_NestedPulsing_0.tim, _1_MockRandom_0.tim, _1_MockRandom_0.sd, _3_MockRandom_0.tib, _4_Lucene41_0.tip, _4_Lucene41_0.tim, _1.fdx, _1_Lucene41_0.pos, _3_Lucene41_0.doc, _1_MockFixedIntBlock_0.skp, _3_NestedPulsing_0.tip, _1.fdt, _4_MockRandom_0.sd, _4_MockFixedIntBlock_0.doc, _4_MockFixedIntBlock_0.frq, _3_MockRandom_0.tiv, _3.si, _1_MockRandom_0.doc, _1_MockFixedIntBlock_0.pos, _1_MockRandom_0.frq, _3_MockFixedIntBlock_0.frq, _1_MockFixedIntBlock_0.doc, _3_MockRandom_0.doc, _3_MockFixedIntBlock_0.doc, _3_MockRandom_0.frq, _3.fnm, _1_NestedPulsing_0.doc, _3_Lucene41_0.tip, _4_NestedPulsing_0.tip, _4_NestedPulsing_0.tim, _3_Lucene41_0.tim, _4_MockFixedIntBlock_0.pyl, _4_MockRandom_0.skp, _1_MockFixedIntBlock_0.tii, _4_NestedPulsing_0.pos, _3_NestedPulsing_0.pos, _1_Lucene41_0.tim, _3_MockFixedIntBlock_0.tib, _1_Lucene41_0.tip, _4.si, _4.fdt, _1_MockRandom_0.skp, _3_MockFixedIntBlock_0.pos, _3_MockRandom_0.sd, _3.fdx, _3_NestedPulsing_0.doc, _4.nvd, _1_MockRandom_0.pyl, _4_MockRandom_0.frq, _1.si, _3_MockRandom_0.pyl, _1_MockFixedIntBlock_0.tib, segments_5, _4.nvm, _3_MockRandom_0.pos, _3_MockFixedIntBlock_0.tii]
[junit4:junit4] 2> 7478 T36 C9 oasc.SolrDeletionPolicy.updateCommits newest commit = 5[_4_MockRandom_0.pos, _1_NestedPulsing_0.tip, _1_Lucene41_0.doc, _4_MockRandom_0.tii, _4_MockFixedIntBlock_0.tib, _3_MockFixedIntBlock_0.skp, _4_NestedPulsing_0.doc, _4_Lucene41_0.doc, _1_MockFixedIntBlock_0.pyl, _4.fnm, _4_MockRandom_0.tib, _3.fdt, _1_MockRandom_0.pos, _1.fnm, _4.fdx, _4_MockRandom_0.doc, _3_MockFixedIntBlock_0.pyl, _3.nvd, _3_Lucene41_0.pos, _4_MockFixedIntBlock_0.tii, _3_MockRandom_0.skp, _4_MockRandom_0.pyl, _4_Lucene41_0.pos, _3.nvm, _1_NestedPulsing_0.tim, _1.nvm, _4_MockFixedIntBlock_0.pos, _1_MockFixedIntBlock_0.frq, _4_MockFixedIntBlock_0.skp, _1_MockRandom_0.tip, _1.nvd, _1_NestedPulsing_0.pos, _3_NestedPulsing_0.tim, _1_MockRandom_0.tim, _1_MockRandom_0.sd, _3_MockRandom_0.tib, _4_Lucene41_0.tip, _4_Lucene41_0.tim, _1.fdx, _1_Lucene41_0.pos, _3_Lucene41_0.doc, _1_MockFixedIntBlock_0.skp, _3_NestedPulsing_0.tip, _1.fdt, _4_MockRandom_0.sd, _4_MockFixedIntBlock_0.doc, _4_MockFixedIntBlock_0.frq, _3_MockRandom_0.tiv, _3.si, _1_MockRandom_0.doc, _1_MockFixedIntBlock_0.pos, _1_MockRandom_0.frq, _3_MockFixedIntBlock_0.frq, _1_MockFixedIntBlock_0.doc, _3_MockRandom_0.doc, _3_MockFixedIntBlock_0.doc, _3_MockRandom_0.frq, _3.fnm, _1_NestedPulsing_0.doc, _3_Lucene41_0.tip, _4_NestedPulsing_0.tip, _4_NestedPulsing_0.tim, _3_Lucene41_0.tim, _4_MockFixedIntBlock_0.pyl, _4_MockRandom_0.skp, _1_MockFixedIntBlock_0.tii, _4_NestedPulsing_0.pos, _3_NestedPulsing_0.pos, _1_Lucene41_0.tim, _3_MockFixedIntBlock_0.tib, _1_Lucene41_0.tip, _4.si, _4.fdt, _1_MockRandom_0.skp, _3_MockFixedIntBlock_0.pos, _3_MockRandom_0.sd, _3.fdx, _3_NestedPulsing_0.doc, _4.nvd, _1_MockRandom_0.pyl, _4_MockRandom_0.frq, _1.si, _3_MockRandom_0.pyl, _1_MockFixedIntBlock_0.tib, segments_5, _4.nvm, _3_MockRandom_0.pos, _3_MockFixedIntBlock_0.tii]
[junit4:junit4] 2> 7480 T36 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 7481 T36 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J1/./solrtest-SoftAutoCommitTest-1363861546645/index
[junit4:junit4] 2> 7481 T36 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J1/./solrtest-SoftAutoCommitTest-1363861546645/index
[junit4:junit4] 2> 7482 T36 oasc.CachingDirectoryFactory.close Closing directory when closing factory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J1/./solrtest-SoftAutoCommitTest-1363861546645
[junit4:junit4] 2> 7482 T36 oasc.CachingDirectoryFactory.closeDirectory Closing directory: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J1/./solrtest-SoftAutoCommitTest-1363861546645
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {timestamp=PostingsFormat(name=NestedPulsing), range_facet_l=PostingsFormat(name=NestedPulsing), id=Lucene41(blocksize=128), range_facet_sl=PostingsFormat(name=MockRandom), text=PostingsFormat(name=MockRandom), range_facet_si=MockFixedIntBlock(blockSize=1577), subject=MockFixedIntBlock(blockSize=1577), multiDefault=MockFixedIntBlock(blockSize=1577), intDefault=PostingsFormat(name=NestedPulsing)}, docValues:{}, sim=RandomSimilarityProvider(queryNorm=false,coord=crazy): {}, locale=fr_LU, timezone=America/Manaus
[junit4:junit4] 2> NOTE: FreeBSD 9.0-RELEASE amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=1,free=371059824,total=461438976
[junit4:junit4] 2> NOTE: All tests run in this JVM: [UpdateRequestProcessorFactoryTest, BadIndexSchemaTest, DefaultValueUpdateProcessorTest, TestLuceneMatchVersion, AutoCommitTest, DirectUpdateHandlerTest, SoftAutoCommitTest]
[junit4:junit4] Completed on J1 in 7.51s, 3 tests, 1 failure <<< FAILURES!
[...truncated 50 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.SyncSliceTest
[junit4:junit4] 2> 0 T256 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /
[junit4:junit4] 2> 5 T256 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./solrtest-SyncSliceTest-1363861554839
[junit4:junit4] 2> 6 T256 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 7 T257 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 9 T257 oazs.ZooKeeperServer.setTickTime tickTime set to 1000
[junit4:junit4] 2> 9 T257 oazs.ZooKeeperServer.setMinSessionTimeout minSessionTimeout set to -1
[junit4:junit4] 2> 9 T257 oazs.ZooKeeperServer.setMaxSessionTimeout maxSessionTimeout set to -1
[junit4:junit4] 2> 10 T257 oazs.NIOServerCnxnFactory.configure binding to port 0.0.0.0/0.0.0.0:0
[junit4:junit4] 2> 11 T257 oazsp.FileTxnSnapLog.save Snapshotting: 0x0 to /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-1363861554838/zookeeper/server1/data/version-2/snapshot.0
[junit4:junit4] 2> 108 T256 oasc.ZkTestServer.run start zk server on port:26764
[junit4:junit4] 2> 108 T256 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26764 sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@74be95bf
[junit4:junit4] 2> 109 T256 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 109 T262 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26764. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 110 T262 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26764, initiating session
[junit4:junit4] 2> 110 T258 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:26765
[junit4:junit4] 2> 111 T258 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:26765
[junit4:junit4] 2> 111 T260 oazsp.FileTxnLog.append Creating new log file: log.1
[junit4:junit4] 2> 113 T260 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8c7bc69c0000 with negotiated timeout 10000 for client /140.211.11.196:26765
[junit4:junit4] 2> 113 T262 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26764, sessionid = 0x13d8c7bc69c0000, negotiated timeout = 10000
[junit4:junit4] 2> 114 T263 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@74be95bf name:ZooKeeperConnection Watcher:127.0.0.1:26764 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 114 T256 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 114 T256 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 117 T261 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8c7bc69c0000
[junit4:junit4] 2> 130 T263 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 130 T256 oaz.ZooKeeper.close Session: 0x13d8c7bc69c0000 closed
[junit4:junit4] 2> 130 T258 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:26765 which had sessionid 0x13d8c7bc69c0000
[junit4:junit4] 2> 131 T256 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26764/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@36fc4957
[junit4:junit4] 2> 131 T256 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 132 T264 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26764. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 132 T264 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26764, initiating session
[junit4:junit4] 2> 132 T258 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:26766
[junit4:junit4] 2> 133 T258 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:26766
[junit4:junit4] 2> 134 T260 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8c7bc69c0001 with negotiated timeout 10000 for client /140.211.11.196:26766
[junit4:junit4] 2> 134 T264 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26764, sessionid = 0x13d8c7bc69c0001, negotiated timeout = 10000
[junit4:junit4] 2> 134 T265 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@36fc4957 name:ZooKeeperConnection Watcher:127.0.0.1:26764/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 134 T256 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 135 T256 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 139 T256 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 142 T256 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 145 T256 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 148 T256 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 149 T256 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 161 T256 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1/conf/schema.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 162 T256 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 167 T256 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 167 T256 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 171 T256 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 172 T256 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 181 T256 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 182 T256 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 189 T256 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 190 T256 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 194 T256 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 195 T256 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 199 T256 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 200 T256 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 203 T256 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 204 T256 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 209 T261 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8c7bc69c0001
[junit4:junit4] 2> 210 T265 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 210 T258 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:26766 which had sessionid 0x13d8c7bc69c0001
[junit4:junit4] 2> 210 T256 oaz.ZooKeeper.close Session: 0x13d8c7bc69c0001 closed
[junit4:junit4] 2> 408 T256 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 418 T256 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:26767
[junit4:junit4] 2> 419 T256 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 420 T256 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 420 T256 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1363861555044
[junit4:junit4] 2> 421 T256 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1363861555044/solr.xml
[junit4:junit4] 2> 422 T256 oasc.CoreContainer.<init> New CoreContainer 2096221691
[junit4:junit4] 2> 423 T256 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1363861555044/'
[junit4:junit4] 2> 424 T256 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1363861555044/'
[junit4:junit4] 2> 488 T256 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 489 T256 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 489 T256 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 490 T256 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 490 T256 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 491 T256 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 491 T256 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 492 T256 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 492 T256 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 493 T256 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 610 T256 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 632 T256 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:26764/solr
[junit4:junit4] 2> 655 T256 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 656 T256 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26764 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@38e02fc4
[junit4:junit4] 2> 657 T256 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 658 T275 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26764. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 659 T275 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26764, initiating session
[junit4:junit4] 2> 659 T258 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:26768
[junit4:junit4] 2> 660 T258 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:26768
[junit4:junit4] 2> 663 T260 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8c7bc69c0002 with negotiated timeout 20000 for client /140.211.11.196:26768
[junit4:junit4] 2> 663 T275 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26764, sessionid = 0x13d8c7bc69c0002, negotiated timeout = 20000
[junit4:junit4] 2> 664 T276 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@38e02fc4 name:ZooKeeperConnection Watcher:127.0.0.1:26764 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 664 T256 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 666 T261 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8c7bc69c0002
[junit4:junit4] 2> 679 T258 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:26768 which had sessionid 0x13d8c7bc69c0002
[junit4:junit4] 2> 679 T276 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 679 T256 oaz.ZooKeeper.close Session: 0x13d8c7bc69c0002 closed
[junit4:junit4] 2> 686 T256 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 707 T256 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26764/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@162098ff
[junit4:junit4] 2> 709 T256 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 710 T277 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26764. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 710 T277 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26764, initiating session
[junit4:junit4] 2> 711 T258 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:26769
[junit4:junit4] 2> 711 T258 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:26769
[junit4:junit4] 2> 713 T260 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8c7bc69c0003 with negotiated timeout 20000 for client /140.211.11.196:26769
[junit4:junit4] 2> 713 T277 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26764, sessionid = 0x13d8c7bc69c0003, negotiated timeout = 20000
[junit4:junit4] 2> 714 T278 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@162098ff name:ZooKeeperConnection Watcher:127.0.0.1:26764/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 714 T256 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 719 T256 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 726 T261 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8c7bc69c0003 type:create cxid:0x7 zxid:0x1b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 729 T256 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 737 T256 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 741 T256 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:26767_
[junit4:junit4] 2> 743 T261 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8c7bc69c0003 type:delete cxid:0x12 zxid:0x1e txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:26767_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:26767_
[junit4:junit4] 2> 744 T256 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:26767_
[junit4:junit4] 2> 752 T256 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 769 T261 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8c7bc69c0003 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> 770 T256 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 776 T256 oasc.Overseer.start Overseer (id=89382030858256387-127.0.0.1:26767_-n_0000000000) starting
[junit4:junit4] 2> 778 T261 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8c7bc69c0003 type:create cxid:0x25 zxid:0x25 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 804 T261 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8c7bc69c0003 type:create cxid:0x26 zxid:0x26 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 807 T261 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8c7bc69c0003 type:create cxid:0x28 zxid:0x27 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 810 T256 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 832 T261 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8c7bc69c0003 type:create cxid:0x2e zxid:0x29 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 840 T280 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 841 T256 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 847 T256 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 850 T256 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 887 T279 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 890 T281 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1363861555044/collection1
[junit4:junit4] 2> 890 T281 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 891 T281 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 891 T281 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 893 T281 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1363861555044/collection1/'
[junit4:junit4] 2> 894 T281 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-controljetty-1363861555044/collection1/lib/README' to classloader
[junit4:junit4] 2> 895 T281 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-controljetty-1363861555044/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 953 T281 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 993 T281 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 994 T281 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 1003 T281 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 1444 T281 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 1458 T281 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1464 T281 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1495 T281 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1500 T281 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1503 T281 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1505 T281 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1505 T281 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 1505 T281 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 1506 T281 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 1507 T281 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 1507 T281 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1507 T281 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-controljetty-1363861555044/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1363861554838/control/data/
[junit4:junit4] 2> 1510 T281 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7a2431b9
[junit4:junit4] 2> 1511 T281 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1511 T281 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1363861554838/control/data forceNew: false
[junit4:junit4] 2> 1512 T281 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1363861554838/control/data/index/
[junit4:junit4] 2> 1512 T281 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1363861554838/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1513 T281 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1363861554838/control/data/index forceNew: false
[junit4:junit4] 2> 1516 T281 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@2b108691 lockFactory=org.apache.lucene.store.NativeFSLockFactory@4d9cad9d)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 1517 T281 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 1557 T281 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1557 T281 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1558 T281 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1559 T281 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1560 T281 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1560 T281 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1560 T281 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1561 T281 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1562 T281 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1569 T281 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1577 T281 oass.SolrIndexSearcher.<init> Opening Searcher@36edc33d main
[junit4:junit4] 2> 1583 T281 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.SyncSliceTest-1363861554838/control/data/tlog
[junit4:junit4] 2> 1601 T281 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1602 T281 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1606 T282 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@36edc33d main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1606 T281 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1607 T281 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 2396 T279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 2397 T279 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "node_name":"127.0.0.1:26767_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:26767"}
[junit4:junit4] 2> 2397 T279 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 2423 T279 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 2462 T278 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> 2610 T281 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 2610 T281 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:26767 collection:control_collection shard:shard1
[junit4:junit4] 2> 2621 T281 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=10000&maxConnectionsPerHost=20&connTimeout=30000&socketTimeout=30000&retry=false
[junit4:junit4] 2> 2635 T281 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 2664 T261 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8c7bc69c0003 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> 2665 T281 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 2666 T261 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8c7bc69c0003 type:create cxid:0x83 zxid:0x36 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 2670 T281 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 2671 T281 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 2671 T281 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:26767/collection1/
[junit4:junit4] 2> 2672 T281 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 2672 T281 oasc.SyncStrategy.syncToMe http://127.0.0.1:26767/collection1/ has no replicas
[junit4:junit4] 2> 2672 T281 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:26767/collection1/
[junit4:junit4] 2> 2673 T281 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 2679 T261 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8c7bc69c0003 type:create cxid:0x8e zxid:0x3a txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 3968 T279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 3994 T278 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> 4017 T281 oasc.ZkController.register We are http://127.0.0.1:26767/collection1/ and leader is http://127.0.0.1:26767/collection1/
[junit4:junit4] 2> 4020 T281 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:26767
[junit4:junit4] 2> 4020 T281 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 4020 T281 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 4020 T281 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 4023 T281 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 4024 T256 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0
[junit4:junit4] 2> 4024 T256 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 4025 T256 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 4034 T256 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 4037 T256 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26764/solr sessionTimeout=10000 watcher=org.apache.solr.common.cloud.ConnectionManager@6a19f410
[junit4:junit4] 2> 4039 T256 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 4039 T283 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26764. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 4040 T283 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26764, initiating session
[junit4:junit4] 2> 4040 T258 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:26770
[junit4:junit4] 2> 4040 T258 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:26770
[junit4:junit4] 2> 4042 T260 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8c7bc69c0004 with negotiated timeout 10000 for client /140.211.11.196:26770
[junit4:junit4] 2> 4042 T283 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26764, sessionid = 0x13d8c7bc69c0004, negotiated timeout = 10000
[junit4:junit4] 2> 4042 T284 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6a19f410 name:ZooKeeperConnection Watcher:127.0.0.1:26764/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 4042 T256 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 4044 T256 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 4051 T256 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 4217 T256 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 4220 T256 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:26771
[junit4:junit4] 2> 4221 T256 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 4222 T256 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 4222 T256 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1363861558884
[junit4:junit4] 2> 4222 T256 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1363861558884/solr.xml
[junit4:junit4] 2> 4223 T256 oasc.CoreContainer.<init> New CoreContainer 935932219
[junit4:junit4] 2> 4223 T256 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1363861558884/'
[junit4:junit4] 2> 4224 T256 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1363861558884/'
[junit4:junit4] 2> 4260 T256 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 4261 T256 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 4261 T256 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 4261 T256 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 4262 T256 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 4262 T256 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 4262 T256 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 4263 T256 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 4263 T256 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 4263 T256 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 4285 T256 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 4300 T256 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:26764/solr
[junit4:junit4] 2> 4301 T256 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 4301 T256 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26764 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@78373ac0
[junit4:junit4] 2> 4302 T256 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 4302 T294 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26764. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 4303 T294 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26764, initiating session
[junit4:junit4] 2> 4304 T258 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:26772
[junit4:junit4] 2> 4304 T258 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:26772
[junit4:junit4] 2> 4306 T260 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8c7bc69c0005 with negotiated timeout 20000 for client /140.211.11.196:26772
[junit4:junit4] 2> 4306 T294 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26764, sessionid = 0x13d8c7bc69c0005, negotiated timeout = 20000
[junit4:junit4] 2> 4307 T295 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@78373ac0 name:ZooKeeperConnection Watcher:127.0.0.1:26764 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 4307 T256 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 4309 T261 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8c7bc69c0005
[junit4:junit4] 2> 4316 T258 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:26772 which had sessionid 0x13d8c7bc69c0005
[junit4:junit4] 2> 4316 T295 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 4316 T256 oaz.ZooKeeper.close Session: 0x13d8c7bc69c0005 closed
[junit4:junit4] 2> 4317 T256 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 4330 T256 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26764/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@302720f6
[junit4:junit4] 2> 4331 T256 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 4331 T296 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26764. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 4332 T296 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26764, initiating session
[junit4:junit4] 2> 4332 T258 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:26773
[junit4:junit4] 2> 4333 T258 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:26773
[junit4:junit4] 2> 4334 T260 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8c7bc69c0006 with negotiated timeout 20000 for client /140.211.11.196:26773
[junit4:junit4] 2> 4334 T296 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26764, sessionid = 0x13d8c7bc69c0006, negotiated timeout = 20000
[junit4:junit4] 2> 4335 T297 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@302720f6 name:ZooKeeperConnection Watcher:127.0.0.1:26764/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 4335 T256 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 4336 T261 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8c7bc69c0006 type:create cxid:0x1 zxid:0x48 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 4338 T261 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8c7bc69c0006 type:create cxid:0x3 zxid:0x49 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 4347 T256 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 5353 T256 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:26771_
[junit4:junit4] 2> 5355 T261 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8c7bc69c0006 type:delete cxid:0xd zxid:0x4a txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:26771_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:26771_
[junit4:junit4] 2> 5369 T256 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:26771_
[junit4:junit4] 2> 5374 T297 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 5374 T278 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 5374 T284 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 5374 T278 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> 5391 T298 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1363861558884/collection1
[junit4:junit4] 2> 5391 T298 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 5392 T298 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 5392 T298 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 5394 T298 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1363861558884/collection1/'
[junit4:junit4] 2> 5394 T298 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty1-1363861558884/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 5395 T298 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty1-1363861558884/collection1/lib/README' to classloader
[junit4:junit4] 2> 5441 T298 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 5484 T298 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 5485 T298 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 5493 T298 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 5510 T279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 5511 T279 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "node_name":"127.0.0.1:26767_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:26767"}
[junit4:junit4] 2> 5524 T278 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> 5524 T284 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> 5525 T297 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> 5946 T298 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 5956 T298 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 5960 T298 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 5981 T298 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 5986 T298 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 5991 T298 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 5993 T298 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 5993 T298 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 5994 T298 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 5995 T298 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 5995 T298 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 5996 T298 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 5996 T298 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty1-1363861558884/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1363861554838/jetty1/
[junit4:junit4] 2> 5996 T298 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7a2431b9
[junit4:junit4] 2> 5997 T298 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 5997 T298 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1363861554838/jetty1 forceNew: false
[junit4:junit4] 2> 5997 T298 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1363861554838/jetty1/index/
[junit4:junit4] 2> 5998 T298 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1363861554838/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 5998 T298 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1363861554838/jetty1/index forceNew: false
[junit4:junit4] 2> 6000 T298 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@5d087070 lockFactory=org.apache.lucene.store.NativeFSLockFactory@2e0e62f6)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 6001 T298 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 6008 T298 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 6009 T298 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 6009 T298 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 6010 T298 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 6011 T298 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 6011 T298 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 6012 T298 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 6013 T298 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 6013 T298 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 6022 T298 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 6030 T298 oass.SolrIndexSearcher.<init> Opening Searcher@61dd1c39 main
[junit4:junit4] 2> 6031 T298 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.SyncSliceTest-1363861554838/jetty1/tlog
[junit4:junit4] 2> 6032 T298 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 6033 T298 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 6040 T299 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@61dd1c39 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 6043 T298 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 6043 T298 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 7039 T279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 7041 T279 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[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:26771_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:26771"}
[junit4:junit4] 2> 7042 T279 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 1
[junit4:junit4] 2> 7042 T279 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 7123 T297 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> 7123 T278 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> 7123 T284 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> 8047 T298 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 8047 T298 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:26771 collection:collection1 shard:shard1
[junit4:junit4] 2> 8049 T298 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 8078 T261 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8c7bc69c0006 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> 8084 T298 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 8085 T261 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8c7bc69c0006 type:create cxid:0x4b zxid:0x5b txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8090 T298 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 8090 T298 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 8090 T298 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:26771/collection1/
[junit4:junit4] 2> 8091 T298 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 8091 T298 oasc.SyncStrategy.syncToMe http://127.0.0.1:26771/collection1/ has no replicas
[junit4:junit4] 2> 8091 T298 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:26771/collection1/
[junit4:junit4] 2> 8092 T298 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 8100 T261 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8c7bc69c0006 type:create cxid:0x56 zxid:0x5f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 8630 T279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 8661 T278 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> 8661 T297 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> 8661 T284 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> 8671 T298 oasc.ZkController.register We are http://127.0.0.1:26771/collection1/ and leader is http://127.0.0.1:26771/collection1/
[junit4:junit4] 2> 8671 T298 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:26771
[junit4:junit4] 2> 8671 T298 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 8671 T298 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 8672 T298 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 8674 T298 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 8675 T256 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0
[junit4:junit4] 2> 8675 T256 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 8676 T256 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 8868 T256 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 8871 T256 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:26777
[junit4:junit4] 2> 8871 T256 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 8872 T256 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 8872 T256 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1363861563522
[junit4:junit4] 2> 8872 T256 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1363861563522/solr.xml
[junit4:junit4] 2> 8873 T256 oasc.CoreContainer.<init> New CoreContainer 1742391956
[junit4:junit4] 2> 8873 T256 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1363861563522/'
[junit4:junit4] 2> 8874 T256 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1363861563522/'
[junit4:junit4] 2> 8924 T256 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 8925 T256 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 8925 T256 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 8926 T256 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 8926 T256 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 8926 T256 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 8927 T256 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 8927 T256 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 8927 T256 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 8928 T256 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 8947 T256 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 8967 T256 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:26764/solr
[junit4:junit4] 2> 8967 T256 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 8968 T256 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26764 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@7c3f6843
[junit4:junit4] 2> 8969 T256 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 8969 T309 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26764. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 8970 T309 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26764, initiating session
[junit4:junit4] 2> 8970 T258 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:26778
[junit4:junit4] 2> 8971 T258 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:26778
[junit4:junit4] 2> 8973 T260 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8c7bc69c0007 with negotiated timeout 20000 for client /140.211.11.196:26778
[junit4:junit4] 2> 8973 T309 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26764, sessionid = 0x13d8c7bc69c0007, negotiated timeout = 20000
[junit4:junit4] 2> 8974 T310 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@7c3f6843 name:ZooKeeperConnection Watcher:127.0.0.1:26764 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 8974 T256 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 8975 T261 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8c7bc69c0007
[junit4:junit4] 2> 8986 T310 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 8986 T256 oaz.ZooKeeper.close Session: 0x13d8c7bc69c0007 closed
[junit4:junit4] 2> 8986 T258 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:26778 which had sessionid 0x13d8c7bc69c0007
[junit4:junit4] 2> 8987 T256 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 8995 T256 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26764/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@76bc3ed6
[junit4:junit4] 2> 8995 T256 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 8996 T311 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26764. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 8996 T311 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26764, initiating session
[junit4:junit4] 2> 8997 T258 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:26779
[junit4:junit4] 2> 8997 T258 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:26779
[junit4:junit4] 2> 8998 T260 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8c7bc69c0008 with negotiated timeout 20000 for client /140.211.11.196:26779
[junit4:junit4] 2> 8998 T311 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26764, sessionid = 0x13d8c7bc69c0008, negotiated timeout = 20000
[junit4:junit4] 2> 8999 T312 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@76bc3ed6 name:ZooKeeperConnection Watcher:127.0.0.1:26764/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 8999 T256 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 9000 T261 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8c7bc69c0008 type:create cxid:0x1 zxid:0x6c txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 9002 T261 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8c7bc69c0008 type:create cxid:0x3 zxid:0x6d txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 9010 T256 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 10015 T256 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:26777_
[junit4:junit4] 2> 10015 T261 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8c7bc69c0008 type:delete cxid:0xd zxid:0x6e txntype:-1 reqpath:n/a Error Path:/solr/live_nodes/127.0.0.1:26777_ Error:KeeperErrorCode = NoNode for /solr/live_nodes/127.0.0.1:26777_
[junit4:junit4] 2> 10017 T256 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:26777_
[junit4:junit4] 2> 10021 T284 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> 10021 T312 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 10021 T297 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 10021 T278 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 10022 T278 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> 10022 T297 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> 10027 T284 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 10043 T313 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1363861563522/collection1
[junit4:junit4] 2> 10043 T313 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 10044 T313 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 10044 T313 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 10046 T313 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1363861563522/collection1/'
[junit4:junit4] 2> 10047 T313 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty2-1363861563522/collection1/lib/README' to classloader
[junit4:junit4] 2> 10047 T313 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/org.apache.solr.cloud.SyncSliceTest-jetty2-1363861563522/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 10084 T313 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_42
[junit4:junit4] 2> 10130 T313 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 10132 T313 oass.IndexSchema.readSchema Reading Solr Schema
[junit4:junit4] 2> 10139 T313 oass.IndexSchema.readSchema Schema name=test
[junit4:junit4] 2> 10170 T279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 10171 T279 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[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:26771_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:26771"}
[junit4:junit4] 2> 10183 T278 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> 10183 T297 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> 10183 T284 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> 10184 T312 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> 10615 T313 oass.OpenExchangeRatesOrgProvider.init Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4:junit4] 2> 10624 T313 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 10626 T313 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 10650 T313 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 10658 T313 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 10664 T313 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 10665 T313 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 10666 T313 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 10666 T313 oass.OpenExchangeRatesOrgProvider.reload Reloading exchange rates from open-exchange-rates.json
[junit4:junit4] 2> 10668 T313 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Unknown key IMPORTANT NOTE
[junit4:junit4] 2> 10668 T313 oass.OpenExchangeRatesOrgProvider$OpenExchangeRates.<init> WARNING Expected key, got STRING
[junit4:junit4] 2> 10669 T313 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 10669 T313 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty2-1363861563522/collection1/, dataDir=./org.apache.solr.cloud.SyncSliceTest-1363861554838/jetty2/
[junit4:junit4] 2> 10669 T313 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@7a2431b9
[junit4:junit4] 2> 10670 T313 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 10671 T313 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1363861554838/jetty2 forceNew: false
[junit4:junit4] 2> 10671 T313 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.SyncSliceTest-1363861554838/jetty2/index/
[junit4:junit4] 2> 10671 T313 oasc.SolrCore.initIndex WARNING [collection1] Solr index directory './org.apache.solr.cloud.SyncSliceTest-1363861554838/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 10672 T313 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.SyncSliceTest-1363861554838/jetty2/index forceNew: false
[junit4:junit4] 2> 10675 T313 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits:num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(RateLimitedDirectoryWrapper(org.apache.lucene.store.RAMDirectory@547d5b6e lockFactory=org.apache.lucene.store.NativeFSLockFactory@3329aa21)),segFN=segments_1,generation=1,filenames=[segments_1]
[junit4:junit4] 2> 10675 T313 oasc.SolrDeletionPolicy.updateCommits newest commit = 1[segments_1]
[junit4:junit4] 2> 10679 T313 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 10679 T313 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 10680 T313 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 10681 T313 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 10682 T313 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 10682 T313 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 10683 T313 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 10683 T313 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 10684 T313 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 10692 T313 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 10698 T313 oass.SolrIndexSearcher.<init> Opening Searcher@7178820c main
[junit4:junit4] 2> 10699 T313 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.SyncSliceTest-1363861554838/jetty2/tlog
[junit4:junit4] 2> 10700 T313 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 10700 T313 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 10707 T314 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@7178820c main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 10710 T313 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 10710 T313 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 11691 T279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 11693 T279 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[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:26777_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:26777"}
[junit4:junit4] 2> 11693 T279 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=1
[junit4:junit4] 2> 11693 T279 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard shard=shard1
[junit4:junit4] 2> 11716 T312 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> 11716 T297 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> 11716 T284 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> 11716 T278 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> 12715 T313 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 12715 T313 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:26777 collection:collection1 shard:shard1
[junit4:junit4] 2> 12719 T313 oasc.ZkController.register We are http://127.0.0.1:26777/collection1/ and leader is http://127.0.0.1:26771/collection1/
[junit4:junit4] 2> 12719 T313 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:26777
[junit4:junit4] 2> 12720 T313 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 12720 T313 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C12 name=collection1 org.apache.solr.core.SolrCore@7987b796 url=http://127.0.0.1:26777/collection1 node=127.0.0.1:26777_ C12_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:26777_, base_url=http://127.0.0.1:26777}
[junit4:junit4] 2> 12726 T315 C12 P26777 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 12727 T315 C12 P26777 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 12727 T313 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 12727 T315 C12 P26777 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 12727 T315 C12 P26777 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 12739 T256 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0
[junit4:junit4] 2> 12740 T315 C12 P26777 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 12740 T256 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 12741 T256 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 12913 T256 oejs.Server.doStart jetty-8.1.8.v20121106
[junit4:junit4] 2> 12916 T256 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:26785
[junit4:junit4] 2> 12916 T256 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 12917 T256 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 12917 T256 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty3-1363861567592
[junit4:junit4] 2> 12917 T256 oasc.CoreContainer$Initializer.initialize looking for solr.xml: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty3-1363861567592/solr.xml
[junit4:junit4] 2> 12918 T256 oasc.CoreContainer.<init> New CoreContainer 827130243
[junit4:junit4] 2> 12918 T256 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty3-1363861567592/'
[junit4:junit4] 2> 12918 T256 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build/solr-core/test/J0/./org.apache.solr.cloud.SyncSliceTest-jetty3-1363861567592/'
[junit4:junit4] 2> 12954 T256 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 12954 T256 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 12955 T256 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 12955 T256 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 12955 T256 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 12956 T256 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 12956 T256 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 12956 T256 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 12957 T256 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 12957 T256 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 12975 T256 oasc.CoreContainer.load Registering Log Listener
[junit4:junit4] 2> 12990 T256 oasc.CoreContainer.initZooKeeper Zookeeper client=127.0.0.1:26764/solr
[junit4:junit4] 2> 12991 T256 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 12991 T256 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26764 sessionTimeout=60000 watcher=org.apache.solr.common.cloud.ConnectionManager@6bb0b0a0
[junit4:junit4] 2> 13002 T256 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 13002 T325 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26764. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 13003 T325 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26764, initiating session
[junit4:junit4] 2> 13003 T258 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:26786
[junit4:junit4] 2> 13003 T258 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:26786
[junit4:junit4] 2> 13005 T260 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8c7bc69c0009 with negotiated timeout 20000 for client /140.211.11.196:26786
[junit4:junit4] 2> 13005 T325 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26764, sessionid = 0x13d8c7bc69c0009, negotiated timeout = 20000
[junit4:junit4] 2> 13006 T326 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@6bb0b0a0 name:ZooKeeperConnection Watcher:127.0.0.1:26764 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 13006 T256 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 13007 T261 oazs.PrepRequestProcessor.pRequest2Txn Processed session termination for sessionid: 0x13d8c7bc69c0009
[junit4:junit4] 2> 13008 T326 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 13008 T256 oaz.ZooKeeper.close Session: 0x13d8c7bc69c0009 closed
[junit4:junit4] 2> 13008 T258 oazs.NIOServerCnxn.closeSock Closed socket connection for client /140.211.11.196:26786 which had sessionid 0x13d8c7bc69c0009
[junit4:junit4] 2> 13009 T256 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 13018 T256 oaz.ZooKeeper.<init> Initiating client connection, connectString=127.0.0.1:26764/solr sessionTimeout=30000 watcher=org.apache.solr.common.cloud.ConnectionManager@50d4855d
[junit4:junit4] 2> 13019 T256 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 13019 T327 oaz.ClientCnxn$SendThread.logStartConnect Opening socket connection to server localhost/127.0.0.1:26764. Will not attempt to authenticate using SASL (access denied (javax.security.auth.AuthPermission getLoginConfiguration))
[junit4:junit4] 2> 13020 T327 oaz.ClientCnxn$SendThread.primeConnection Socket connection established to localhost/127.0.0.1:26764, initiating session
[junit4:junit4] 2> 13020 T258 oazs.NIOServerCnxnFactory.run Accepted socket connection from /140.211.11.196:26787
[junit4:junit4] 2> 13021 T258 oazs.ZooKeeperServer.processConnectRequest Client attempting to establish new session at /140.211.11.196:26787
[junit4:junit4] 2> 13022 T260 oazs.ZooKeeperServer.finishSessionInit Established session 0x13d8c7bc69c000a with negotiated timeout 20000 for client /140.211.11.196:26787
[junit4:junit4] 2> 13022 T327 oaz.ClientCnxn$SendThread.onConnected Session establishment complete on server localhost/127.0.0.1:26764, sessionid = 0x13d8c7bc69c000a, negotiated timeout = 20000
[junit4:junit4] 2> 13022 T328 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@50d4855d name:ZooKeeperConnection Watcher:127.0.0.1:26764/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 13022 T256 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 13023 T261 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8c7bc69c000a type:create cxid:0x1 zxid:0x7f txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 13028 T261 oazs.PrepRequestProcessor.pRequest Got user-level KeeperException when processing sessionid:0x13d8c7bc69c000a type:create cxid:0x3 zxid:0x80 txntype:-1 reqpath:n/a Error Path:/solr/overseer Error:KeeperErrorCode = NodeExists for /solr/overseer
[junit4:junit4] 2> 13031 T256 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 13257 T279 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 13258 T279 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[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:26777_",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:26777"}
[junit4:junit4] 2> 13273 T278 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> 13273 T328 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> 13273 T297 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has oc
[...truncated too long message...]
1062624249
[junit4:junit4] 2> 181740 T382 oasc.CachingDirectoryFactory.closeDirectory Closing directory: ./org.apache.solr.cloud.SyncSliceTest-1363861554838/jetty6/index.20130321062624249
[junit4:junit4] 2> 181740 T382 oasc.CachingDirectoryFactory.close Closing directory when closing factory: ./org.apache.solr.cloud.SyncSliceTest-1363861554838/jetty6/index
[junit4:junit4] 2> 181740 T382 oasc.CachingDirectoryFactory.closeDirectory Closing directory: ./org.apache.solr.cloud.SyncSliceTest-1363861554838/jetty6/index
[junit4:junit4] 2> 181741 T382 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> 181741 T382 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 181741 T382 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 181741 T382 oasc.LeaderElector$1.process WARNING org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
[junit4:junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4:junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4:junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:236)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:233)
[junit4:junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:233)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:84)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4:junit4] 2>
[junit4:junit4] 2> 181742 T382 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> 182790 T400 oasu.PeerSync.handleResponse WARNING PeerSync: core=collection1 url=http://127.0.0.1:26820 couldn't connect to http://127.0.0.1:26811/collection1/, counting as success
[junit4:junit4] 2> 182790 T400 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:26820 DONE. sync succeeded
[junit4:junit4] 2> 182790 T400 oasc.SyncStrategy.syncReplicas We have been closed, won't attempt to sync replicas back to leader
[junit4:junit4] 2> 182791 T400 oasc.ShardLeaderElectionContext.rejoinLeaderElection Not rejoining election because CoreContainer is shutdown
[junit4:junit4] 2> 182792 T400 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@6b414655
[junit4:junit4] 2> 182793 T400 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=10,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=305,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4:junit4] 2> 182794 T400 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 182794 T400 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 182794 T400 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 182794 T400 C18 P26820 oasu.TransactionLog.forceClose SEVERE Error: Forcing close of tlog{file=./org.apache.solr.cloud.SyncSliceTest-1363861554838/jetty7/tlog/tlog.0000000000000000005 refcount=1}
[junit4:junit4] 2> 182796 T400 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 182797 T400 oasc.CachingDirectoryFactory.close Closing directory when closing factory: ./org.apache.solr.cloud.SyncSliceTest-1363861554838/jetty7/index
[junit4:junit4] 2> 182797 T400 oasc.CachingDirectoryFactory.closeDirectory Closing directory: ./org.apache.solr.cloud.SyncSliceTest-1363861554838/jetty7/index
[junit4:junit4] 2> 182797 T400 oasc.CachingDirectoryFactory.close Closing directory when closing factory: ./org.apache.solr.cloud.SyncSliceTest-1363861554838/jetty7/index.20130321062627241
[junit4:junit4] 2> 182797 T400 oasc.CachingDirectoryFactory.closeDirectory Removing directory: ./org.apache.solr.cloud.SyncSliceTest-1363861554838/jetty7/index.20130321062627241
[junit4:junit4] 2> 182797 T400 oasc.CachingDirectoryFactory.closeDirectory Closing directory: ./org.apache.solr.cloud.SyncSliceTest-1363861554838/jetty7/index.20130321062627241
[junit4:junit4] 2> 182798 T400 oasc.CachingDirectoryFactory.close Closing directory when closing factory: ./org.apache.solr.cloud.SyncSliceTest-1363861554838/jetty7
[junit4:junit4] 2> 182798 T400 oasc.CachingDirectoryFactory.closeDirectory Closing directory: ./org.apache.solr.cloud.SyncSliceTest-1363861554838/jetty7
[junit4:junit4] 2> 182798 T400 oasc.LeaderElector$1.process WARNING org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
[junit4:junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4:junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4:junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:236)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:233)
[junit4:junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:233)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:84)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4:junit4] 2>
[junit4:junit4] 2> 182798 T400 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> 182799 T400 oascc.ZkStateReader$2.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 182799 T400 oascc.ZkStateReader$3.process WARNING ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 182799 T400 oaz.ClientCnxn$EventThread.run EventThread shut down
[junit4:junit4] 2> NOTE: test params are: codec=Lucene42: {range_facet_l=MockVariableIntBlock(baseBlockSize=57), text=PostingsFormat(name=Memory doPackFST= false), _version_=MockVariableIntBlock(baseBlockSize=57), rnd_b=Pulsing41(freqCutoff=8 minBlockSize=60 maxBlockSize=119), intDefault=MockVariableIntBlock(baseBlockSize=57), id=Pulsing41(freqCutoff=8 minBlockSize=60 maxBlockSize=119), timestamp=MockVariableIntBlock(baseBlockSize=57), a_t=PostingsFormat(name=SimpleText), range_facet_sl=Pulsing41(freqCutoff=8 minBlockSize=60 maxBlockSize=119), range_facet_si=PostingsFormat(name=SimpleText), other_tl1=MockVariableIntBlock(baseBlockSize=57), multiDefault=MockVariableIntBlock(baseBlockSize=57), a_si=MockVariableIntBlock(baseBlockSize=57)}, docValues:{}, sim=DefaultSimilarity, locale=ar_OM, timezone=America/Montreal
[junit4:junit4] 2> NOTE: FreeBSD 9.0-RELEASE amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=5,free=378136816,total=475987968
[junit4:junit4] 2> NOTE: All tests run in this JVM: [DocumentAnalysisRequestHandlerTest, ExternalFileFieldSortTest, CacheHeaderTest, QueryElevationComponentTest, LeaderElectionTest, IndexSchemaRuntimeFieldTest, TestPropInjectDefaults, TestSolrDeletionPolicy1, ResponseLogComponentTest, SyncSliceTest]
[junit4:junit4] Completed on J0 in 183.28s, 1 test, 1 failure <<< FAILURES!
[...truncated 751 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/build.xml:388: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/build.xml:361: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/build.xml:183: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/solr/common-build.xml:449: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/lucene/common-build.xml:1213: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-NightlyTests-4.2.1/lucene/common-build.xml:877: There were test failures: 269 suites, 1133 tests, 2 failures, 23 ignored (4 assumptions)
Total time: 99 minutes 35 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure